Hello everyone,
I've updated my CloudStack management server and an agent from 4.13.1 to
4.15.0. I am running Ubuntu 18.04 server. Following the instructions in the
documentation on the upgrade steps, the management server and the agent started
ok. I've logged in to the new GUI and at first things seem ok. However, I've
noticed that I can't perform any vm / systemvm related operations. Things like
start/stop/migrate/shutdown vms produce a 503 error. Also, I wasn't able to add
a host running 4.15.0 agent. Inspecting the management server logs I get the
following exception, which happens with pretty much any vm related action.
------------------
2021-03-28 02:28:46,811 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-6:ctx-cfe07062 job-81025 ctx-2387e198) (logid:c5396488) Found
no ongoing snapshots on volumes associated with th
e vm with id 695
2021-03-28 02:28:46,813 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-6:ctx-cfe07062 job-81025 ctx-2387e198) (logid:c5396488)
Collect vm disk statistics from host before stopping VM
2021-03-28 02:28:46,879 DEBUG [c.c.a.t.Request] (AgentManager-Handler-14:null)
(logid Seq 121-4330211041716731948: Processing: { Ans: , MgmtId:
115129173025114, via: 121, Ver: v1, Fla
gs: 10,
[{"com.cloud.agent.api.GetVmDiskStatsAnswer":{"hostName":"ais-cloudhost13","vmDiskStatsMap":{"i-2-695-VM":[]},"result":"true","details":"","wait":"0"}}]
}
2021-03-28 02:28:46,879 DEBUG [c.c.a.t.Request]
(API-Job-Executor-6:ctx-cfe07062 job-81025 ctx-2387e198) (logid:c5396488) Seq
121-4330211041716731948: Received: { Ans: , MgmtId: 1151291
73025114, via: 121(ais-cloudhost13), Ver: v1, Flags: 10, { GetVmDiskStatsAnswer
} }
2021-03-28 02:28:46,879 DEBUG [c.c.a.m.AgentManagerImpl]
(API-Job-Executor-6:ctx-cfe07062 job-81025 ctx-2387e198) (logid:c5396488)
Details from executing class com.cloud.agent.api.GetVmD
iskStatsCommand:
2021-03-28 02:28:46,880 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-6:ctx-cfe07062 job-81025 ctx-2387e198) (logid:c5396488)
Collect vm network statistics from host before stopping
Vm
2021-03-28 02:28:46,897 DEBUG [c.c.a.t.Request] (AgentManager-Handler-1:null)
(logid Seq 121-4330211041716731949: Processing: { Ans: , MgmtId:
115129173025114, via: 121, Ver: v1, Flag
s: 10,
[{"com.cloud.agent.api.GetVmNetworkStatsAnswer":{"hostName":"ais-cloudhost13","vmNetworkStatsMap":{"i-2-695-VM":[{"vmName":"i-2-695-VM","macAddress":"02:00:20:a5:00:01","bytesSent
":"(335.09 MB) 351364549","bytesReceived":"(294.63 MB)
308940852"},{"vmName":"i-2-695-VM","macAddress":"06:c7:fe:00:01:0b","bytesSent":"(74.57
KB) 76358","bytesReceived":"(585.85 MB) 614
310467"}]},"result":"true","details":"","wait":"0"}}] }
2021-03-28 02:28:46,897 DEBUG [c.c.a.t.Request]
(API-Job-Executor-6:ctx-cfe07062 job-81025 ctx-2387e198) (logid:c5396488) Seq
121-4330211041716731949: Received: { Ans: , MgmtId: 1151291
73025114, via: 121(ais-cloudhost13), Ver: v1, Flags: 10, {
GetVmNetworkStatsAnswer } }
2021-03-28 02:28:46,897 DEBUG [c.c.a.m.AgentManagerImpl]
(API-Job-Executor-6:ctx-cfe07062 job-81025 ctx-2387e198) (logid:c5396488)
Details from executing class com.cloud.agent.api.GetVmN
etworkStatsCommand:
2021-03-28 02:28:46,909 WARN [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-cfe07062 job-81025 ctx-2387e198) (logid:c5396488)
Unable to schedule async job for command com.clo
ud.vm.VmWorkMigrate, unexpected exception.
com.cloud.utils.exception.CloudRuntimeException: Unable to lock vm_instance695.
Waited 0
at com.cloud.utils.db.Merovingian2.doAcquire(Merovingian2.java:197)
at com.cloud.utils.db.Merovingian2.acquire(Merovingian2.java:137)
at com.cloud.utils.db.TransactionLegacy.lock(TransactionLegacy.java:384)
at com.cloud.utils.db.GenericDaoBase.lockInLockTable(GenericDaoBase.java:1075)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:34)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com. sun .proxy.$Proxy91.lockInLockTable(Unknown Source)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:231)
at
com.cloud.vm.VirtualMachineManagerImpl.migrateVmThroughJobQueue(VirtualMachineManagerImpl.java:5101)
at
com.cloud.vm.VirtualMachineManagerImpl.migrate(VirtualMachineManagerImpl.java:2443)
at
com.cloud.vm.UserVmManagerImpl.migrateVirtualMachine(UserVmManagerImpl.java:5845)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com. sun .proxy.$Proxy124.migrateVirtualMachine(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd.execute(MigrateVMCmd.java:173)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: com.mysql.cj.jdbc.exceptions.MysqlDataTruncation: Data truncation:
Incorrect datetime value: ' 2021-03-28 01:28:46' for column 'acquired_on' at
row 1
at
com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:104)
at
com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:953)
at
com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1092)
... 56 more
2021-03-28 02:28:46,947 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-6:ctx-cfe07062 job-81025) (logid:c5396488) Unexpected
exception while executing
org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd
com.cloud.utils.exception.CloudRuntimeException: Unable to schedule async job
for command com.cloud.vm.VmWorkMigrate, unexpected exception.
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:253)
at
com.cloud.vm.VirtualMachineManagerImpl.migrateVmThroughJobQueue(VirtualMachineManagerImpl.java:5101)
at
com.cloud.vm.VirtualMachineManagerImpl.migrate(VirtualMachineManagerImpl.java:2443)
at
com.cloud.vm.UserVmManagerImpl.migrateVirtualMachine(UserVmManagerImpl.java:5845)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com. sun .proxy.$Proxy124.migrateVirtualMachine(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd.execute(MigrateVMCmd.java:173)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
2021-03-28 02:28:46,949 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-cfe07062 job-81025) (logid:c5396488) Complete async
job-81025, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"530","errortext":"Unable
to schedule async job for command com.cloud.vm.VmWorkMigrate, unexpected
exception."}
--------------
>From what I can see, the following line shows the reason for the exception:
Caused by: com.mysql.cj.jdbc.exceptions.MysqlDataTruncation: Data truncation:
Incorrect datetime value: ' 2021-03-28 01:28:46' for column 'acquired_on' at
row 1
I wasn't able to determine how to fix the issue. Perhaps there were some issues
with upgrading the database tables? Could someone help me get my CloudStack
cluster up and running again?
Cheers
Andrei
