Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 7A74F11B6A for ; Thu, 15 May 2014 04:22:28 +0000 (UTC) Received: (qmail 64095 invoked by uid 500); 14 May 2014 18:55:17 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 64065 invoked by uid 500); 14 May 2014 18:55:17 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 64051 invoked by uid 500); 14 May 2014 18:55:17 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 63963 invoked by uid 99); 14 May 2014 18:55:17 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 14 May 2014 18:55:17 +0000 Date: Wed, 14 May 2014 18:55:17 +0000 (UTC) From: "Rayees Namathponnan (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (CLOUDSTACK-6674) [Automation] [DB lock] When KVM agent is alert state, agent never trying to connect back MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-6674?page=3Dcom.atl= assian.jira.plugin.system.issuetabpanels:all-tabpanel ] Rayees Namathponnan updated CLOUDSTACK-6674: -------------------------------------------- Description:=20 This issue observed in automation run, when KVM agent is alert state, it n= ever tries to connect back, also observed SQL DB lock in MS log for AgentC= onnectTaskPool You need to restart agent manually to connect it back=20 Here is agent log=20 2014-05-13 23:59:38,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:38,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progre ss. 2014-05-13 23:59:43,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:43,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progre ss. 2014-05-13 23:59:48,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:48,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progre ss. 2014-05-13 23:59:53,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:53,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progre ss. 2014-05-13 23:59:58,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:58,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progress. ~ MS log, please see the attached log for more info 2014-05-13 20:07:50,170 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Ex= ecutor-93:job-2240 ctx-f6efb16a) Destroying vm VM[User|i-137-304-QA] 2014-05-13 20:07:50,171 DEBUG [c.c.u.d.T.Transaction] (API-Job-Executor-65:= job-2223 ctx-a60be5ae) Rolling back the transaction: Time =3D 291 Name =3D = API-Job-Ex ecutor-65; called by -TransactionLegacy.rollback:903-TransactionLegacy.remo= veUpTo:846-TransactionLegacy.close:670-TransactionContextInterceptor.invoke= :36-Ref lectiveMethodInvocation.proceed:161-ExposeInvocationInterceptor.invoke:91-R= eflectiveMethodInvocation.proceed:172-JdkDynamicAopProxy.invoke:204-$Proxy9= 7.markA sUnavailable:-1-IpAddressManagerImpl$10.doInTransaction:1639-IpAddressManag= erImpl$10.doInTransaction:1620-Transaction$2.doInTransaction:49 2014-05-13 20:07:50,173 WARN [c.c.u.AccountManagerImpl] (API-Job-Executor-= 65:job-2223 ctx-a60be5ae) Failed to cleanup account Acct[20c063c7-9913-496d= -983f-e fe18a92a9dc-test-account-TestScaleVmDynamicServiceOffering-test_change_so_r= unning_vm_dynamic_to_dynamic_1_ADMIN] due to com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql= .jdbc.PreparedStatement@76384607: UPDATE user_ip_address SET user_ip_addres= s.state =3D'Releasing' WHERE user_ip_address.id =3D 15 at com.cloud.utils.db.GenericDaoBase.update(GenericDaoBase.java:851= ) at com.cloud.utils.db.GenericDaoBase.update(GenericDaoBase.java:132= 7) at com.cloud.network.dao.IPAddressDaoImpl.markAsUnavailable(IPAddre= ssDaoImpl.java:323) at sun.reflect.GeneratedMethodAccessor536.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethod= AccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingRef= lection(AopUtils.java:317) at org.springframework.aop.framework.ReflectiveMethodInvocation.inv= okeJoinpoint(ReflectiveMethodInvocation.java:183) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:150) at com.cloud.utils.db.TransactionContextInterceptor.invoke(Transact= ionContextInterceptor.java:34) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:161) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.= invoke(ExposeInvocationInterceptor.java:91) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkD= ynamicAopProxy.java:204) at com.sun.proxy.$Proxy97.markAsUnavailable(Unknown Source) at com.cloud.network.IpAddressManagerImpl$10.doInTransaction(IpAddr= essManagerImpl.java:1639) at com.cloud.network.IpAddressManagerImpl$10.doInTransaction(IpAddr= essManagerImpl.java:1620) at com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.jav= a:49) at com.cloud.utils.db.Transaction.execute(Transaction.java:37) at com.cloud.utils.db.Transaction.execute(Transaction.java:46) at com.cloud.network.IpAddressManagerImpl.markIpAsUnavailable(IpAdd= ressManagerImpl.java:1620) at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.c= leanupNetworkResources(NetworkOrchestrator.java:2616) at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.d= estroyNetwork(NetworkOrchestrator.java:2177) at com.cloud.user.AccountManagerImpl.cleanupAccount(AccountManagerI= mpl.java:815) at com.cloud.user.AccountManagerImpl.deleteAccount(AccountManagerIm= pl.java:689) at com.cloud.user.AccountManagerImpl.deleteUserAccount(AccountManag= erImpl.java:1464) at sun.reflect.GeneratedMethodAccessor555.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethod= AccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.cloud.user.AccountManagerImpl.deleteAccount(AccountManagerIm= pl.java:689) at com.cloud.user.AccountManagerImpl.deleteUserAccount(AccountManag= erImpl.java:1464) at sun.reflect.GeneratedMethodAccessor555.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethod= AccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingRef= lection(AopUtils.java:317) at org.springframework.aop.framework.ReflectiveMethodInvocation.inv= okeJoinpoint(ReflectiveMethodInvocation.java:183) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:150) at org.apache.cloudstack.network.contrail.management.EventUtils$Eve= ntInterceptor.invoke(EventUtils.java:106) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:161) at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterce= ptor.java:51) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:161) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.= invoke(ExposeInvocationInterceptor.java:91) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkD= ynamicAopProxy.java:204) at com.sun.proxy.$Proxy100.deleteUserAccount(Unknown Source) at org.apache.cloudstack.region.RegionManagerImpl.deleteUserAccount= (RegionManagerImpl.java:187) at org.apache.cloudstack.region.RegionServiceImpl.deleteUserAccount= (RegionServiceImpl.java:121) at org.apache.cloudstack.api.command.admin.account.DeleteAccountCmd= .execute(DeleteAccountCmd.java:104) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:119) at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher= .java:108) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.= runInContext(AsyncJobManagerImpl.java:496) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.r= un(ManagedContextRunnable.java:49) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext= $1.call(DefaultManagedContext.java:56) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext= .callWithContext(DefaultManagedContext.java:103) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext= .runWithContext(DefaultManagedContext.java:53) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run= (ManagedContextRunnable.java:46) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.= run(AsyncJobManagerImpl.java:453) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.ja= va:471) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:615) at java.lang.Thread.run(Thread.java:744) Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackExceptio= n: Deadlock found when trying to get lock; try restarting transaction =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 140513 20:07:49 INNODB MONITOR OUTPUT =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D Per second averages calculated from the last 15 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 86171, signal count 75053 Mutex spin waits 0, rounds 1468094, OS waits 30100 RW-shared spins 106570, OS waits 49606; RW-excl spins 8147, OS waits 6463 ------------------------ ------------------------ LATEST FOREIGN KEY ERROR ------------------------ 140513 18:36:59 Transaction: TRANSACTION 0 1892217502, ACTIVE 0 sec, process no 1449, OS thread id 14058= 0633499392 inserting, thread declared inside InnoDB 500 mysql tables in use 1, locked 1 5 lock struct(s), heap size 1216, 2 row lock(s), undo log entries 1 MySQL thread id 3304, query id 1818700312 localhost 127.0.0.1 cloud update INSERT INTO op_ha_work (op_ha_work.instance_id, op_ha_work.mgmt_server_id, = op_ha_work.created, op_ha_work.state, op_ha_work.host_id, op_ha_work.taken,= op_ha_work.time_to_try, op_ha_work.type, op_ha_work.updated, op_ha_work.st= ep, op_ha_work.vm_type, op_ha_work.tried) VALUES (152, null, '2014-05-14 01= :36:59', 'Stopped', 0, null, 1367218183, 'HA', 3, 'Investigating', 'User', = 1) Foreign key constraint fails for table `cloud`.`op_ha_work`: , CONSTRAINT `fk_op_ha_work__host_id` FOREIGN KEY (`host_id`) REFERENCES `h= ost` (`id`) Trying to add in child table, in index `i_op_ha_work__host_id` tuple: DATA TUPLE: 2 fields; 0: len 8; hex 0000000000000000; asc ;; 1: len 8; hex 0000000000000= 01e; asc ;; But in parent table `cloud`.`host`, in index `PRIMARY`, the closest match we can find is record: PHYSICAL RECORD: n_fields 50; compact format; info bits 0 0: len 8; hex 0000000000000001; asc ;; 1: len 6; hex 000070c8e312;= asc p ;; 2: len 7; hex 000000296610fd; asc )f ;; 3: len 25; hex 52= 61636b32486f737431312e6c61622e766d6f70732e636f6d; asc Rack2Host11.lab.vmops= .com;; 4: len 30; hex 64333337373432652d653934642d343033302d626132392d33613= 2653463; asc d337742e-e94d-4030-ba29-3a2e4c;...(truncated); 5: len 5; hex 4= 16c657274; asc Alert;; 6: len 7; hex 526f7574696e67; asc Routing;; 7: len 3= 0; hex 31302e3232332e35302e3636202020202020202020202020202020202020; asc 10= .223.50.66 ;...(truncated); 8: len 15; hex 3235352e3235352= e3235352e313932; asc 255.255.255.192;; 9: len 17; hex 62633a33303a35623a643= 43a35333a3233; asc bc:30:5b:d4:53:23;; 10: len 30; hex 31302e3232332e35302e= 3636202020202020202020202020202020202020; asc 10.223.50.66 = ;...(truncated); 11: len 15; hex 3235352e3235352e3235352e313932; asc 255.2= 55.255.192;; 12: len 17; hex 62633a33303a35623a64343a35333a3233; asc bc:30:= 5b:d4:53:23;; 13: SQL NULL; 14: SQL NULL; 15: SQL NULL; 16: len 8; hex 0000= 000000000001; asc ;; 17: len 30; hex 31302e3232332e35302e3636202020= 202020202020202020202020202020; asc 10.223.50.66 ;...(trun= cated); 18: len 15; hex 3235352e3235352e3235352e313932; asc 255.255.255.192= ;; 19: len 17; hex 62633a33303a35623a64343a35333a3233; asc bc:30:5b:d4:53:2= 3;; 20: SQL NULL; 21: len 8; hex 0000000000000001; asc ;; 22: len 8= ; hex 0000000000000001; asc ;; 23: len 4; hex 00000001; asc ;; = 24: len 4; hex 00000004; asc ;; 25: len 4; hex 000008d5; asc ;; 26:= SQL NULL; 27: SQL NULL; 28: len 3; hex 4b564d; asc KVM;; 29: SQL NULL; 30:= len 8; hex 00000003e430c000; asc 0 ;; 31: SQL NULL; 32: len 14; hex = 342e342e302d534e415053484f54; asc 4.4.0-SNAPSHOT;; 33: SQL NULL; 34: SQL NU= LL; 35: len 12; hex 68766d2c736e617073686f74; asc hvm,snapshot;; 36: len 30= ; hex 38313731636466622d306434372d333239632d393835382d383739633434; asc 817= 1cdfb-0d47-329c-9858-879c44;...(truncated); 37: len 4; hex 00000001; asc = ;; 38: len 4; hex 00000000; asc ;; 39: len 8; hex 0000000000000000; a= sc ;; 40: len 4; hex 517dfc67; asc Q} g;; 41: SQL NULL; 42: len 8; = hex 8000125154230a85; asc QT# ;; 43: len 8; hex 80001251542304fb; asc = QT# ;; 44: SQL NULL; 45: len 8; hex 0000000000000006; asc ;; 46:= len 7; hex 456e61626c6564; asc Enabled;; 47: SQL NULL; 48: SQL NULL; 49: l= en 8; hex 44697361626c6564; asc Disabled;; ------------------------ LATEST DETECTED DEADLOCK ------------------------ 140513 20:07:49 *** (1) TRANSACTION: TRANSACTION 0 1899231769, ACTIVE 0 sec, process no 1449, OS thread id 14058= 0624189184 starting index read mysql tables in use 1, locked 1 was: This issue observed in automation run, when KVM agent is alert state, it n= ever tries to connect back, also observed SQL DB lock in MS log for AgentC= onnectTaskPool You need to restart agent manually to connect it back=20 Here is agent log=20 2014-05-13 23:59:38,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:38,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progre ss. 2014-05-13 23:59:43,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:43,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progre ss. 2014-05-13 23:59:48,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:48,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progre ss. 2014-05-13 23:59:53,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:53,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progre ss. 2014-05-13 23:59:58,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Lo= st connection to the server. Dealing with the remaining commands... 2014-05-13 23:59:58,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Ca= nnot connect because we still have 5 commands in progress. ~ MS log=20 2014-05-13 20:07:50,170 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Ex= ecutor-93:job-2240 ctx-f6efb16a) Destroying vm VM[User|i-137-304-QA] 2014-05-13 20:07:50,171 DEBUG [c.c.u.d.T.Transaction] (API-Job-Executor-65:= job-2223 ctx-a60be5ae) Rolling back the transaction: Time =3D 291 Name =3D = API-Job-Ex ecutor-65; called by -TransactionLegacy.rollback:903-TransactionLegacy.remo= veUpTo:846-TransactionLegacy.close:670-TransactionContextInterceptor.invoke= :36-Ref lectiveMethodInvocation.proceed:161-ExposeInvocationInterceptor.invoke:91-R= eflectiveMethodInvocation.proceed:172-JdkDynamicAopProxy.invoke:204-$Proxy9= 7.markA sUnavailable:-1-IpAddressManagerImpl$10.doInTransaction:1639-IpAddressManag= erImpl$10.doInTransaction:1620-Transaction$2.doInTransaction:49 2014-05-13 20:07:50,173 WARN [c.c.u.AccountManagerImpl] (API-Job-Executor-= 65:job-2223 ctx-a60be5ae) Failed to cleanup account Acct[20c063c7-9913-496d= -983f-e fe18a92a9dc-test-account-TestScaleVmDynamicServiceOffering-test_change_so_r= unning_vm_dynamic_to_dynamic_1_ADMIN] due to com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql= .jdbc.PreparedStatement@76384607: UPDATE user_ip_address SET user_ip_addres= s.state =3D'Releasing' WHERE user_ip_address.id =3D 15 at com.cloud.utils.db.GenericDaoBase.update(GenericDaoBase.java:851= ) at com.cloud.utils.db.GenericDaoBase.update(GenericDaoBase.java:132= 7) at com.cloud.network.dao.IPAddressDaoImpl.markAsUnavailable(IPAddre= ssDaoImpl.java:323) at sun.reflect.GeneratedMethodAccessor536.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethod= AccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingRef= lection(AopUtils.java:317) at org.springframework.aop.framework.ReflectiveMethodInvocation.inv= okeJoinpoint(ReflectiveMethodInvocation.java:183) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:150) at com.cloud.utils.db.TransactionContextInterceptor.invoke(Transact= ionContextInterceptor.java:34) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:161) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.= invoke(ExposeInvocationInterceptor.java:91) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkD= ynamicAopProxy.java:204) at com.sun.proxy.$Proxy97.markAsUnavailable(Unknown Source) at com.cloud.network.IpAddressManagerImpl$10.doInTransaction(IpAddr= essManagerImpl.java:1639) at com.cloud.network.IpAddressManagerImpl$10.doInTransaction(IpAddr= essManagerImpl.java:1620) at com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.jav= a:49) at com.cloud.utils.db.Transaction.execute(Transaction.java:37) at com.cloud.utils.db.Transaction.execute(Transaction.java:46) at com.cloud.network.IpAddressManagerImpl.markIpAsUnavailable(IpAdd= ressManagerImpl.java:1620) at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.c= leanupNetworkResources(NetworkOrchestrator.java:2616) at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.d= estroyNetwork(NetworkOrchestrator.java:2177) at com.cloud.user.AccountManagerImpl.cleanupAccount(AccountManagerI= mpl.java:815) at com.cloud.user.AccountManagerImpl.deleteAccount(AccountManagerIm= pl.java:689) at com.cloud.user.AccountManagerImpl.deleteUserAccount(AccountManag= erImpl.java:1464) at sun.reflect.GeneratedMethodAccessor555.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethod= AccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.cloud.user.AccountManagerImpl.deleteAccount(AccountManagerIm= pl.java:689) at com.cloud.user.AccountManagerImpl.deleteUserAccount(AccountManag= erImpl.java:1464) at sun.reflect.GeneratedMethodAccessor555.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethod= AccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingRef= lection(AopUtils.java:317) at org.springframework.aop.framework.ReflectiveMethodInvocation.inv= okeJoinpoint(ReflectiveMethodInvocation.java:183) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:150) at org.apache.cloudstack.network.contrail.management.EventUtils$Eve= ntInterceptor.invoke(EventUtils.java:106) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:161) at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterce= ptor.java:51) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:161) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.= invoke(ExposeInvocationInterceptor.java:91) at org.springframework.aop.framework.ReflectiveMethodInvocation.pro= ceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkD= ynamicAopProxy.java:204) at com.sun.proxy.$Proxy100.deleteUserAccount(Unknown Source) at org.apache.cloudstack.region.RegionManagerImpl.deleteUserAccount= (RegionManagerImpl.java:187) at org.apache.cloudstack.region.RegionServiceImpl.deleteUserAccount= (RegionServiceImpl.java:121) at org.apache.cloudstack.api.command.admin.account.DeleteAccountCmd= .execute(DeleteAccountCmd.java:104) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:119) at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher= .java:108) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.= runInContext(AsyncJobManagerImpl.java:496) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.r= un(ManagedContextRunnable.java:49) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext= $1.call(DefaultManagedContext.java:56) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext= .callWithContext(DefaultManagedContext.java:103) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext= .runWithContext(DefaultManagedContext.java:53) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run= (ManagedContextRunnable.java:46) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.= run(AsyncJobManagerImpl.java:453) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.ja= va:471) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:615) at java.lang.Thread.run(Thread.java:744) Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackExceptio= n: Deadlock found when trying to get lock; try restarting transaction =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 140513 20:07:49 INNODB MONITOR OUTPUT =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D Per second averages calculated from the last 15 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 86171, signal count 75053 Mutex spin waits 0, rounds 1468094, OS waits 30100 RW-shared spins 106570, OS waits 49606; RW-excl spins 8147, OS waits 6463 ------------------------ ------------------------ LATEST FOREIGN KEY ERROR ------------------------ 140513 18:36:59 Transaction: TRANSACTION 0 1892217502, ACTIVE 0 sec, process no 1449, OS thread id 14058= 0633499392 inserting, thread declared inside InnoDB 500 mysql tables in use 1, locked 1 5 lock struct(s), heap size 1216, 2 row lock(s), undo log entries 1 MySQL thread id 3304, query id 1818700312 localhost 127.0.0.1 cloud update INSERT INTO op_ha_work (op_ha_work.instance_id, op_ha_work.mgmt_server_id, = op_ha_work.created, op_ha_work.state, op_ha_work.host_id, op_ha_work.taken,= op_ha_work.time_to_try, op_ha_work.type, op_ha_work.updated, op_ha_work.st= ep, op_ha_work.vm_type, op_ha_work.tried) VALUES (152, null, '2014-05-14 01= :36:59', 'Stopped', 0, null, 1367218183, 'HA', 3, 'Investigating', 'User', = 1) Foreign key constraint fails for table `cloud`.`op_ha_work`: , CONSTRAINT `fk_op_ha_work__host_id` FOREIGN KEY (`host_id`) REFERENCES `h= ost` (`id`) Trying to add in child table, in index `i_op_ha_work__host_id` tuple: DATA TUPLE: 2 fields; 0: len 8; hex 0000000000000000; asc ;; 1: len 8; hex 0000000000000= 01e; asc ;; But in parent table `cloud`.`host`, in index `PRIMARY`, the closest match we can find is record: PHYSICAL RECORD: n_fields 50; compact format; info bits 0 0: len 8; hex 0000000000000001; asc ;; 1: len 6; hex 000070c8e312;= asc p ;; 2: len 7; hex 000000296610fd; asc )f ;; 3: len 25; hex 52= 61636b32486f737431312e6c61622e766d6f70732e636f6d; asc Rack2Host11.lab.vmops= .com;; 4: len 30; hex 64333337373432652d653934642d343033302d626132392d33613= 2653463; asc d337742e-e94d-4030-ba29-3a2e4c;...(truncated); 5: len 5; hex 4= 16c657274; asc Alert;; 6: len 7; hex 526f7574696e67; asc Routing;; 7: len 3= 0; hex 31302e3232332e35302e3636202020202020202020202020202020202020; asc 10= .223.50.66 ;...(truncated); 8: len 15; hex 3235352e3235352= e3235352e313932; asc 255.255.255.192;; 9: len 17; hex 62633a33303a35623a643= 43a35333a3233; asc bc:30:5b:d4:53:23;; 10: len 30; hex 31302e3232332e35302e= 3636202020202020202020202020202020202020; asc 10.223.50.66 = ;...(truncated); 11: len 15; hex 3235352e3235352e3235352e313932; asc 255.2= 55.255.192;; 12: len 17; hex 62633a33303a35623a64343a35333a3233; asc bc:30:= 5b:d4:53:23;; 13: SQL NULL; 14: SQL NULL; 15: SQL NULL; 16: len 8; hex 0000= 000000000001; asc ;; 17: len 30; hex 31302e3232332e35302e3636202020= 202020202020202020202020202020; asc 10.223.50.66 ;...(trun= cated); 18: len 15; hex 3235352e3235352e3235352e313932; asc 255.255.255.192= ;; 19: len 17; hex 62633a33303a35623a64343a35333a3233; asc bc:30:5b:d4:53:2= 3;; 20: SQL NULL; 21: len 8; hex 0000000000000001; asc ;; 22: len 8= ; hex 0000000000000001; asc ;; 23: len 4; hex 00000001; asc ;; = 24: len 4; hex 00000004; asc ;; 25: len 4; hex 000008d5; asc ;; 26:= SQL NULL; 27: SQL NULL; 28: len 3; hex 4b564d; asc KVM;; 29: SQL NULL; 30:= len 8; hex 00000003e430c000; asc 0 ;; 31: SQL NULL; 32: len 14; hex = 342e342e302d534e415053484f54; asc 4.4.0-SNAPSHOT;; 33: SQL NULL; 34: SQL NU= LL; 35: len 12; hex 68766d2c736e617073686f74; asc hvm,snapshot;; 36: len 30= ; hex 38313731636466622d306434372d333239632d393835382d383739633434; asc 817= 1cdfb-0d47-329c-9858-879c44;...(truncated); 37: len 4; hex 00000001; asc = ;; 38: len 4; hex 00000000; asc ;; 39: len 8; hex 0000000000000000; a= sc ;; 40: len 4; hex 517dfc67; asc Q} g;; 41: SQL NULL; 42: len 8; = hex 8000125154230a85; asc QT# ;; 43: len 8; hex 80001251542304fb; asc = QT# ;; 44: SQL NULL; 45: len 8; hex 0000000000000006; asc ;; 46:= len 7; hex 456e61626c6564; asc Enabled;; 47: SQL NULL; 48: SQL NULL; 49: l= en 8; hex 44697361626c6564; asc Disabled;; ------------------------ LATEST DETECTED DEADLOCK ------------------------ 140513 20:07:49 *** (1) TRANSACTION: TRANSACTION 0 1899231769, ACTIVE 0 sec, process no 1449, OS thread id 14058= 0624189184 starting index read mysql tables in use 1, locked 1 > [Automation] [DB lock] When KVM agent is alert state, agent never trying = to connect back=20 > -------------------------------------------------------------------------= ---------------- > > Key: CLOUDSTACK-6674 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-667= 4 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the defa= ult.)=20 > Components: KVM > Affects Versions: 4.4.0 > Environment: KVM (RHEL 6.3) > 4.4-forward > Reporter: Rayees Namathponnan > Assignee: edison su > Priority: Blocker > Fix For: 4.4.0 > > > This issue observed in automation run, when KVM agent is alert state, it= never tries to connect back, also observed SQL DB lock in MS log for Agen= tConnectTaskPool > You need to restart agent manually to connect it back=20 > Here is agent log=20 > 2014-05-13 23:59:38,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Lost connection to the server. Dealing with the remaining > commands... > 2014-05-13 23:59:38,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Cannot connect because we still have 5 commands in progre > ss. > 2014-05-13 23:59:43,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Lost connection to the server. Dealing with the remaining > commands... > 2014-05-13 23:59:43,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Cannot connect because we still have 5 commands in progre > ss. > 2014-05-13 23:59:48,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Lost connection to the server. Dealing with the remaining > commands... > 2014-05-13 23:59:48,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Cannot connect because we still have 5 commands in progre > ss. > 2014-05-13 23:59:53,877 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Lost connection to the server. Dealing with the remaining > commands... > 2014-05-13 23:59:53,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Cannot connect because we still have 5 commands in progre > ss. > 2014-05-13 23:59:58,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Lost connection to the server. Dealing with the remaining > commands... > 2014-05-13 23:59:58,878 INFO [cloud.agent.Agent] (Agent-Handler-2:null) = Cannot connect because we still have 5 commands in progress. > ~ > MS log, please see the attached log for more info > 2014-05-13 20:07:50,170 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-= Executor-93:job-2240 ctx-f6efb16a) Destroying vm VM[User|i-137-304-QA] > 2014-05-13 20:07:50,171 DEBUG [c.c.u.d.T.Transaction] (API-Job-Executor-6= 5:job-2223 ctx-a60be5ae) Rolling back the transaction: Time =3D 291 Name = =3D API-Job-Ex > ecutor-65; called by -TransactionLegacy.rollback:903-TransactionLegacy.re= moveUpTo:846-TransactionLegacy.close:670-TransactionContextInterceptor.invo= ke:36-Ref > lectiveMethodInvocation.proceed:161-ExposeInvocationInterceptor.invoke:91= -ReflectiveMethodInvocation.proceed:172-JdkDynamicAopProxy.invoke:204-$Prox= y97.markA > sUnavailable:-1-IpAddressManagerImpl$10.doInTransaction:1639-IpAddressMan= agerImpl$10.doInTransaction:1620-Transaction$2.doInTransaction:49 > 2014-05-13 20:07:50,173 WARN [c.c.u.AccountManagerImpl] (API-Job-Executo= r-65:job-2223 ctx-a60be5ae) Failed to cleanup account Acct[20c063c7-9913-49= 6d-983f-e > fe18a92a9dc-test-account-TestScaleVmDynamicServiceOffering-test_change_so= _running_vm_dynamic_to_dynamic_1_ADMIN] due to > com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mys= ql.jdbc.PreparedStatement@76384607: UPDATE user_ip_address SET user_ip_addr= ess.state > =3D'Releasing' WHERE user_ip_address.id =3D 15 > at com.cloud.utils.db.GenericDaoBase.update(GenericDaoBase.java:8= 51) > at com.cloud.utils.db.GenericDaoBase.update(GenericDaoBase.java:1= 327) > at com.cloud.network.dao.IPAddressDaoImpl.markAsUnavailable(IPAdd= ressDaoImpl.java:323) > at sun.reflect.GeneratedMethodAccessor536.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMeth= odAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at org.springframework.aop.support.AopUtils.invokeJoinpointUsingR= eflection(AopUtils.java:317) > at org.springframework.aop.framework.ReflectiveMethodInvocation.i= nvokeJoinpoint(ReflectiveMethodInvocation.java:183) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:150) > at com.cloud.utils.db.TransactionContextInterceptor.invoke(Transa= ctionContextInterceptor.java:34) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:161) > at org.springframework.aop.interceptor.ExposeInvocationIntercepto= r.invoke(ExposeInvocationInterceptor.java:91) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:172) > at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(Jd= kDynamicAopProxy.java:204) > at com.sun.proxy.$Proxy97.markAsUnavailable(Unknown Source) > at com.cloud.network.IpAddressManagerImpl$10.doInTransaction(IpAd= dressManagerImpl.java:1639) > at com.cloud.network.IpAddressManagerImpl$10.doInTransaction(IpAd= dressManagerImpl.java:1620) > at com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.j= ava:49) > at com.cloud.utils.db.Transaction.execute(Transaction.java:37) > at com.cloud.utils.db.Transaction.execute(Transaction.java:46) > at com.cloud.network.IpAddressManagerImpl.markIpAsUnavailable(IpA= ddressManagerImpl.java:1620) > at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator= .cleanupNetworkResources(NetworkOrchestrator.java:2616) > at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator= .destroyNetwork(NetworkOrchestrator.java:2177) > at com.cloud.user.AccountManagerImpl.cleanupAccount(AccountManage= rImpl.java:815) > at com.cloud.user.AccountManagerImpl.deleteAccount(AccountManager= Impl.java:689) > at com.cloud.user.AccountManagerImpl.deleteUserAccount(AccountMan= agerImpl.java:1464) > at sun.reflect.GeneratedMethodAccessor555.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMeth= odAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at com.cloud.user.AccountManagerImpl.deleteAccount(AccountManager= Impl.java:689) > at com.cloud.user.AccountManagerImpl.deleteUserAccount(AccountMan= agerImpl.java:1464) > at sun.reflect.GeneratedMethodAccessor555.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMeth= odAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at org.springframework.aop.support.AopUtils.invokeJoinpointUsingR= eflection(AopUtils.java:317) > at org.springframework.aop.framework.ReflectiveMethodInvocation.i= nvokeJoinpoint(ReflectiveMethodInvocation.java:183) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:150) > at org.apache.cloudstack.network.contrail.management.EventUtils$E= ventInterceptor.invoke(EventUtils.java:106) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:161) > at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInter= ceptor.java:51) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:161) > at org.springframework.aop.interceptor.ExposeInvocationIntercepto= r.invoke(ExposeInvocationInterceptor.java:91) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:172) > at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(Jd= kDynamicAopProxy.java:204) > at com.sun.proxy.$Proxy100.deleteUserAccount(Unknown Source) > at org.apache.cloudstack.region.RegionManagerImpl.deleteUserAccou= nt(RegionManagerImpl.java:187) > at org.apache.cloudstack.region.RegionServiceImpl.deleteUserAccou= nt(RegionServiceImpl.java:121) > at org.apache.cloudstack.api.command.admin.account.DeleteAccountC= md.execute(DeleteAccountCmd.java:104) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:119) > at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatch= er.java:108) > at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$= 5.runInContext(AsyncJobManagerImpl.java:496) > at org.apache.cloudstack.managed.context.ManagedContextRunnable$1= .run(ManagedContextRunnable.java:49) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt$1.call(DefaultManagedContext.java:56) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.callWithContext(DefaultManagedContext.java:103) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.runWithContext(DefaultManagedContext.java:53) > at org.apache.cloudstack.managed.context.ManagedContextRunnable.r= un(ManagedContextRunnable.java:46) > at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$= 5.run(AsyncJobManagerImpl.java:453) > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.= java:471) > at java.util.concurrent.FutureTask.run(FutureTask.java:262) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolEx= ecutor.java:1145) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:615) > at java.lang.Thread.run(Thread.java:744) > Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackExcept= ion: Deadlock found when trying to get lock; try restarting transaction > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > 140513 20:07:49 INNODB MONITOR OUTPUT > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > Per second averages calculated from the last 15 seconds > ---------- > SEMAPHORES > ---------- > OS WAIT ARRAY INFO: reservation count 86171, signal count 75053 > Mutex spin waits 0, rounds 1468094, OS waits 30100 > RW-shared spins 106570, OS waits 49606; RW-excl spins 8147, OS waits 6463 > ------------------------ > ------------------------ > LATEST FOREIGN KEY ERROR > ------------------------ > 140513 18:36:59 Transaction: > TRANSACTION 0 1892217502, ACTIVE 0 sec, process no 1449, OS thread id 140= 580633499392 inserting, thread declared inside InnoDB 500 > mysql tables in use 1, locked 1 > 5 lock struct(s), heap size 1216, 2 row lock(s), undo log entries 1 > MySQL thread id 3304, query id 1818700312 localhost 127.0.0.1 cloud updat= e > INSERT INTO op_ha_work (op_ha_work.instance_id, op_ha_work.mgmt_server_id= , op_ha_work.created, op_ha_work.state, op_ha_work.host_id, op_ha_work.take= n, op_ha_work.time_to_try, op_ha_work.type, op_ha_work.updated, op_ha_work.= step, op_ha_work.vm_type, op_ha_work.tried) VALUES (152, null, '2014-05-14 = 01:36:59', 'Stopped', 0, null, 1367218183, 'HA', 3, 'Investigating', 'User'= , 1) > Foreign key constraint fails for table `cloud`.`op_ha_work`: > , > CONSTRAINT `fk_op_ha_work__host_id` FOREIGN KEY (`host_id`) REFERENCES = `host` (`id`) > Trying to add in child table, in index `i_op_ha_work__host_id` tuple: > DATA TUPLE: 2 fields; > 0: len 8; hex 0000000000000000; asc ;; 1: len 8; hex 00000000000= 0001e; asc ;; > But in parent table `cloud`.`host`, in index `PRIMARY`, > the closest match we can find is record: > PHYSICAL RECORD: n_fields 50; compact format; info bits 0 > 0: len 8; hex 0000000000000001; asc ;; 1: len 6; hex 000070c8e31= 2; asc p ;; 2: len 7; hex 000000296610fd; asc )f ;; 3: len 25; hex = 5261636b32486f737431312e6c61622e766d6f70732e636f6d; asc Rack2Host11.lab.vmo= ps.com;; 4: len 30; hex 64333337373432652d653934642d343033302d626132392d336= 132653463; asc d337742e-e94d-4030-ba29-3a2e4c;...(truncated); 5: len 5; hex= 416c657274; asc Alert;; 6: len 7; hex 526f7574696e67; asc Routing;; 7: len= 30; hex 31302e3232332e35302e3636202020202020202020202020202020202020; asc = 10.223.50.66 ;...(truncated); 8: len 15; hex 3235352e32353= 52e3235352e313932; asc 255.255.255.192;; 9: len 17; hex 62633a33303a35623a6= 4343a35333a3233; asc bc:30:5b:d4:53:23;; 10: len 30; hex 31302e3232332e3530= 2e3636202020202020202020202020202020202020; asc 10.223.50.66 = ;...(truncated); 11: len 15; hex 3235352e3235352e3235352e313932; asc 255= .255.255.192;; 12: len 17; hex 62633a33303a35623a64343a35333a3233; asc bc:3= 0:5b:d4:53:23;; 13: SQL NULL; 14: SQL NULL; 15: SQL NULL; 16: len 8; hex 00= 00000000000001; asc ;; 17: len 30; hex 31302e3232332e35302e36362020= 20202020202020202020202020202020; asc 10.223.50.66 ;...(tr= uncated); 18: len 15; hex 3235352e3235352e3235352e313932; asc 255.255.255.1= 92;; 19: len 17; hex 62633a33303a35623a64343a35333a3233; asc bc:30:5b:d4:53= :23;; 20: SQL NULL; 21: len 8; hex 0000000000000001; asc ;; 22: len= 8; hex 0000000000000001; asc ;; 23: len 4; hex 00000001; asc ;= ; 24: len 4; hex 00000004; asc ;; 25: len 4; hex 000008d5; asc ;; 2= 6: SQL NULL; 27: SQL NULL; 28: len 3; hex 4b564d; asc KVM;; 29: SQL NULL; 3= 0: len 8; hex 00000003e430c000; asc 0 ;; 31: SQL NULL; 32: len 14; he= x 342e342e302d534e415053484f54; asc 4.4.0-SNAPSHOT;; 33: SQL NULL; 34: SQL = NULL; 35: len 12; hex 68766d2c736e617073686f74; asc hvm,snapshot;; 36: len = 30; hex 38313731636466622d306434372d333239632d393835382d383739633434; asc 8= 171cdfb-0d47-329c-9858-879c44;...(truncated); 37: len 4; hex 00000001; asc = ;; 38: len 4; hex 00000000; asc ;; 39: len 8; hex 0000000000000000;= asc ;; 40: len 4; hex 517dfc67; asc Q} g;; 41: SQL NULL; 42: len 8= ; hex 8000125154230a85; asc QT# ;; 43: len 8; hex 80001251542304fb; asc= QT# ;; 44: SQL NULL; 45: len 8; hex 0000000000000006; asc ;; 4= 6: len 7; hex 456e61626c6564; asc Enabled;; 47: SQL NULL; 48: SQL NULL; 49:= len 8; hex 44697361626c6564; asc Disabled;; > ------------------------ > LATEST DETECTED DEADLOCK > ------------------------ > 140513 20:07:49 > *** (1) TRANSACTION: > TRANSACTION 0 1899231769, ACTIVE 0 sec, process no 1449, OS thread id 140= 580624189184 starting index read > mysql tables in use 1, locked 1 -- This message was sent by Atlassian JIRA (v6.2#6252)