Closed xuanyuanaosheng closed 1 year ago
rajujith
commented
1 year ago Hi @xuanyuanaosheng CloudStack fetches the secondary storage capacity and utilization using SSVM. Since SSVM deployment failed the reported issue is expected and by design. You could check the management-server.log to identify why SSVM deployment is failing. Once the SSVM is up the secondary storage capacity will be available on the dashboard.
xuanyuanaosheng
commented
1 year ago @rajujith @weizhouapache @DaanHoogland
The zone config: system.vm.use.local.storage is to true
The management-server error log is:
2023-07-05 11:35:05,231 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-7f6d0d0a) (logid:079dbd17) Allocating nic for vm VM instance {id: "30807", name: "s-30807-VM", uuid: "5934da82-a444-4417-9e50-c98b43e5f295", type="SecondaryStorageVm"} in network Network {"id": 243, "name": "defaultGuestNetwork", "uuid": "57d6e97e-74ba-421f-b106-0b1696003460", "networkofferingid": 6} with requested profile NicProfile {"broadcastUri":null,"iPv4Address":null,"id":0,"reservationId":null,"vmId":0}
2023-07-05 11:35:05,257 DEBUG [c.c.u.d.T.Transaction] (secstorage-1:ctx-7f6d0d0a) (logid:079dbd17) Rolling back the transaction: Time = 29 Name = secstorage-1; called by -TransactionLegacy.rollback:888-TransactionLegacy.removeUpTo:831-TransactionLegacy.close:655-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy70.persist:-1-NetworkOrchestrator.allocateNic:997-NetworkOrchestrator$3.addRequestedNicToNicListWithDeviceNumberAndRetrieveDefaultDevice:823-NetworkOrchestrator$3.doInTransactionWithoutResult:797
2023-07-05 11:35:05,265 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-7f6d0d0a) (logid:079dbd17) received secondary storage vm alert
2023-07-05 11:35:05,267 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-7f6d0d0a) (logid:079dbd17) Secondary Storage Vm creation failure, zone: Taida
2023-07-05 11:35:05,269 WARN [c.c.a.AlertManagerImpl] (secstorage-1:ctx-7f6d0d0a) (logid:079dbd17) alertType=[19] dataCenterId=[9] podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. zone: Taida, error details: Unable to allocate capacity on zone [9] due to [null].].
2023-07-05 11:35:05,287 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-68754bdd) (logid:7eeabd68) Seq 80-7496804529711612132: Received: { Ans: , MgmtId: 345052215515, via: 80(whdckvm008.cn.prod), Ver: v1, Flags: 10, { GetVmStatsAnswer } }
2023-07-05 11:35:05,291 WARN [c.c.a.AlertManagerImpl] (secstorage-1:ctx-7f6d0d0a) (logid:079dbd17) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Secondary Storage Vm creation failure. zone: Taida, error details: Unable to allocate capacity on zone [9] due to [null].] and content [Secondary Storage Vm creation failure (zone Taida)].
2023-07-05 11:35:05,292 WARN [c.c.v.SystemVmLoadScanner] (secstorage-1:ctx-7f6d0d0a) (logid:079dbd17) Unexpected exception DB Exception on: com.mysql.cj.jdbc.ClientPreparedStatement: INSERT INTO nics (nics.instance_id, nics.ip4_address, nics.ip6_address, nics.netmask, nics.isolation_uri, nics.ip_type, nics.broadcast_uri, nics.gateway, nics.mac_address, nics.mode, nics.network_id, nics.state, nics.reserver_name, nics.reservation_id, nics.device_id, nics.update_time, nics.default_nic, nics.ip6_gateway, nics.ip6_cidr, nics.strategy, nics.vm_type, nics.created, nics.uuid, nics.secondary_ip) VALUES (30807, x'31302E37302E33332E3838', null, x'3235352E3235352E3235352E30', 'vlan://2333', 'Ip4', 'vlan://2333', x'31302E37302E33332E323534', x'31653A30303A64323A30303A30303A3330', 'Dhcp', 243, 'Allocated', x'4469726563744E6574776F726B47757275', null, 2, null, 1, null, null, 'Create', 'SecondaryStorageVm', '2023-07-05 03:35:05', x'61303865323563302D383438312D346636652D386566372D623839353838643164613536', 0)
com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.cj.jdbc.ClientPreparedStatement: INSERT INTO nics (nics.instance_id, nics.ip4_address, nics.ip6_address, nics.netmask, nics.isolation_uri, nics.ip_type, nics.broadcast_uri, nics.gateway, nics.mac_address, nics.mode, nics.network_id, nics.state, nics.reserver_name, nics.reservation_id, nics.device_id, nics.update_time, nics.default_nic, nics.ip6_gateway, nics.ip6_cidr, nics.strategy, nics.vm_type, nics.created, nics.uuid, nics.secondary_ip) VALUES (30807, x'31302E37302E33332E3838', null, x'3235352E3235352E3235352E30', 'vlan://2333', 'Ip4', 'vlan://2333',
x'31302E37302E33332E323534', x'31653A30303A64323A30303A30303A3330', 'Dhcp', 243, 'Allocated', x'4469726563744E6574776F726B47757275', null, 2, null, 1, null, nu
ll, 'Create', 'SecondaryStorageVm', '2023-07-05 03:35:05', x'61303865323563302D383438312D346636652D386566372D623839353838643164613536', 0)
at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1461)
at jdk.internal.reflect.GeneratedMethodAccessor75.invoke(Unknown Source)
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:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
at com.sun.proxy.$Proxy70.persist(Unknown Source)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.allocateNic(NetworkOrchestrator.java:997)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator$3.addRequestedNicToNicListWithDeviceNumberAndRetrieveDefaultDevice(NetworkOrchestrato
r.java:823)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator$3.doInTransactionWithoutResult(NetworkOrchestrator.java:797)
at com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTransaction(TransactionCallbackWithExceptionNoReturn.java:25)
at com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTransaction(TransactionCallbackWithExceptionNoReturn.java:21)
at com.cloud.utils.db.Transaction.execute(Transaction.java:40)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.allocate(NetworkOrchestrator.java:778)
at com.cloud.vm.VirtualMachineManagerImpl$1.doInTransactionWithoutResult(VirtualMachineManagerImpl.java:478)
at com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTransaction(TransactionCallbackWithExceptionNoReturn.java:25)
at com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTransaction(TransactionCallbackWithExceptionNoReturn.java:21)
at com.cloud.utils.db.Transaction.execute(Transaction.java:40)
at com.cloud.vm.VirtualMachineManagerImpl.allocate(VirtualMachineManagerImpl.java:469)
at com.cloud.vm.VirtualMachineManagerImpl.allocate(VirtualMachineManagerImpl.java:528)
at org.apache.cloudstack.secondarystorage.SecondaryStorageManagerImpl.createSecStorageVmInstance(SecondaryStorageManagerImpl.java:636)
at org.apache.cloudstack.secondarystorage.SecondaryStorageManagerImpl.startNew(SecondaryStorageManagerImpl.java:486)
at org.apache.cloudstack.secondarystorage.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:712)
at org.apache.cloudstack.secondarystorage.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1348)
at org.apache.cloudstack.secondarystorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:147)
at org.apache.cloudstack.secondarystorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:55)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:114)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:91)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:82)
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 java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
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:829)
Caused by: java.sql.SQLIntegrityConstraintViolationException: Column 'update_time' cannot be null
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:117)
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
... 53 more
2023-07-05 11:35:06,036 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-68754bdd) (logid:7eeabd68) Seq 770991-5187020870823968950: Received: { Ans: , MgmtId: 34
5052215515, via: 770991(ljzdckvm003.cn.prod), Ver: v1, Flags: 10, { GetVmStatsAnswer } }
2023-07-05 11:35:07,018 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) (logid:) Ping from Routing host 1192814(ljzdckvm006.cn.prod)
2023-07-05 11:35:07,019 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-1:null) (logid:) Process host VM state report from ping process. h
ost: 1192814
2023-07-05 11:35:07,019 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-1:null) (logid:) Process VM state report. host: 1192814, number of
records in report: 0
2023-07-05 11:35:07,022 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-1:null) (logid:) Done with process of VM state report. host: 11928
14
2023-07-05 11:35:07,158 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-11:null) (logid:) SeqA 84-635699: Processing Seq 84-635699: { Cmd , MgmtId: -1,
via: 84, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"30537","_loadInfo":"{
"connections": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2023-07-05 11:35:35,122 INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-25ec57da) (logid:d5066db4) Found a stopped secondary storage VM instance {id: "30807", name: "s-30807-VM", uuid: "5934da82-a444-4417-9e50-c98b43e5f295", type="SecondaryStorageVm"}, starting it.
2023-07-05 11:35:35,128 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-25ec57da) (logid:d5066db4) start parameter value of enterHardwareSetup == <very null> during processing of queued job
2023-07-05 11:35:35,138 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-21:ctx-079bfce2 job-111378/job-111423 ctx-9ae3792b) (logid:d94c185a) VM instance {id: "30806", name: "v-30806-VM", uuid: "bbf985dc-4847-4fce-a3c8-ac60fa46cf74", type="ConsoleProxy"} state transited from [Starting] to [Stopped] with event [OperationFailed]. VM's original host: null, new host: null, host before state transition: null
2023-07-05 11:35:35,140 WARN [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-21:ctx-079bfce2 job-111378/job-111423 ctx-9ae3792b) (logid:d94c185a) Unable to orchestrate start VM instance {id: "30806", name: "v-30806-VM", uuid: "bbf985dc-4847-4fce-a3c8-ac60fa46cf74", type="ConsoleProxy"} due to [Unable to create deployment, no usable volumes found for the VM: 30806].
com.cloud.utils.exception.CloudRuntimeException: Unable to create deployment, no usable volumes found for the VM: 30806
at com.cloud.deploy.DeploymentPlanningManagerImpl.findSuitablePoolsForVolumes(DeploymentPlanningManagerImpl.java:1569)
at com.cloud.deploy.DeploymentPlanningManagerImpl.checkClustersforDestination(DeploymentPlanningManagerImpl.java:1217)
at com.cloud.deploy.DeploymentPlanningManagerImpl.planDeployment(DeploymentPlanningManagerImpl.java:527)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1126)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5315)
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 com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5439)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
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:829)
2023-07-05 11:35:35,152 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-21:ctx-079bfce2 job-111378/job-111423 ctx-9ae3792b) (logid:d94c185a) Done execut
ing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":30806,"handlerName":"VirtualMachineManagerImpl"}
2023-07-05 11:35:35,155 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-21:ctx-079bfce2 job-111378/job-111423 ctx-9ae3792b) (logid:d94c185a) Complet
e async job-111423, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFc
nJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAF
Y2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHB
yZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AN1VbmFibGUgdG8gb3JjaGVzdHJhdGUgc3RhcnQgVk0gaW5zdGFuY2Uge2lkOiAiMzA4MDYiLCBuYW1lOiAidi0zMDgwNi1WTSIsIH
V1aWQ6ICJiYmY5ODVkYy00ODQ3LTRmY2UtYTNjOC1hYzYwZmE0NmNmNzQiLCB0eXBlPSJDb25zb2xlUHJveHkifSBkdWUgdG8gW1VuYWJsZSB0byBjcmVhdGUgZGVwbG95bWVudCwgbm8gdXNhYmxlIHZvbHVtZ
XMgZm91bmQgZm9yIHRoZSBWTTogMzA4MDZdLnVyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAAFHNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIA
CEIABmZvcm1hdEkACmxpbmVOdW1iZXJMAA9jbGFzc0xvYWRlck5hbWVxAH4ABUwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFTAAKbW9kdWxlTmFtZXEAfgA
FTAANbW9kdWxlVmVyc2lvbnEAfgAFeHABAAAUx3QAA2FwcHQAJmNvbS5jbG91ZC52bS5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsdAAeVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbC5qYXZhdAAQb3JjaGVzdH
JhdGVTdGFydHBwc3EAfgAMAv____5wdAAtamRrLmludGVybmFsLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2UwdAAJamF2Y
S5iYXNldAAHMTEuMC4xOXNxAH4ADAIAAAA-cHEAfgATcQB-ABR0AAZpbnZva2VxAH4AFnEAfgAXc3EAfgAMAgAAACtwdAAxamRrLmludGVybmFsLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1w
bHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAZcQB-ABZxAH4AF3NxAH4ADAIAAAI2cHQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABlxAH4AFnEAfgA
Xc3EAfgAMAQAAAGtxAH4ADnQAImNvbS5jbG91ZC52bS5WbVdvcmtKb2JIYW5kbGVyUHJveHl0ABpWbVdvcmtKb2JIYW5kbGVyUHJveHkuamF2YXQAD2hhbmRsZVZtV29ya0pvYnBwc3EAfgAMAQAAFT9xAH4ADn
EAfgAPcQB-ABBxAH4AI3Bwc3EAfgAMAQAAAGZxAH4ADnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9icHBzcQB-AAwBAAACbHEAf
gAOdAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0cHBzcQB-AAwB
AAAAMHEAfgAOdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5wcHNxAH4ADAE
AAAA3cQB-AA50AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxwcHNxAH
4ADAEAAABmcQB-AA50AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-ADN0AA9jYWxsV2l0aENvbnRleHRwcHNxAH4ADAEAAAA0cQB-A
A5xAH4ANnEAfgAzdAAOcnVuV2l0aENvbnRleHRwcHNxAH4ADAEAAAAtcQB-AA50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AL3EAfgAw
cHBzcQB-AAwBAAACOHEAfgAOcQB-ACpxAH4AK3EAfgAwcHBzcQB-AAwCAAACA3B0AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4ANHE
AfgAWcQB-ABdzcQB-AAwCAAABCHB0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGFzay5qYXZhcQB-ADBxAH4AFnEAfgAXc3EAfgAMAgAABGhwdAAnamF2YS51dGlsLmNvbmN1cn
JlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJxAH4AFnEAfgAXc3EAfgAMAgAAAnRwdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4Z
WN1dG9yJFdvcmtlcnEAfgBFcQB-ADBxAH4AFnEAfgAXc3EAfgAMAgAAAz1wdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-ADBxAH4AFnEAfgAXc3IAH2phdmEudXRpbC5Db2xsZWN0aW9ucyRF
bXB0eUxpc3R6uBe0PKee3gIAAHhweAAAEJp3CAAAAAAAAAAAeA
2023-07-05 11:35:35,158 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-21:ctx-079bfce2 job-111378/job-111423 ctx-9ae3792b) (logid:d94c185a) Publish
async job-111423 complete on message bus
2023-07-05 11:35:35,158 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-21:ctx-079bfce2 job-111378/job-111423 ctx-9ae3792b) (logid:d94c185a) Wake up
jobs related to job-111423
2023-07-05 11:35:35,158 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-21:ctx-079bfce2 job-111378/job-111423 ctx-9ae3792b) (logid:d94c185a) Update
db status for job-111423
2023-07-05 11:35:35,163 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-21:ctx-079bfce2 job-111378/job-111423 ctx-9ae3792b) (logid:d94c185a) Wake up
jobs joined with job-111423 and disjoin all subjobs created from job- 1114232023-07-05 12:49:36,942 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Successfully set Capacity - (4.8828 TB) 5368667176960 for capacity typ
e - 3 , DataCenterId - 10, HostOrPoolId - 138, PodId null
2023-07-05 12:49:36,947 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727) (logid:3d9f0ff3) Executing AsyncJobV
O: {id:111727, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3Rhc
nR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElk
cQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN
0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AA
N4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAB4V3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, result
Code: 0, result: null, initMsid: 345052215515, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Jul 05 12:49:35 CST 2023, removed: null}
2023-07-05 12:49:36,948 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727) (logid:3d9f0ff3) Run VM work job: com.clou
d.vm.VmWorkStart for VM 30807, job origin: 111384
2023-07-05 12:49:36,956 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Execute VM
work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":30807,"handlerName":"VirtualMachineManagerImpl"}
2023-07-05 12:49:36,957 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Found storage pool ljzdckvm002.cn.prod-local-9a21555e of type Filesyst
em with overprovisioning factor 2
2023-07-05 12:49:36,957 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Total over provisioned capacity calculated is 2 * (49.98 GB) 536608768
00
2023-07-05 12:49:36,957 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Total over provisioned capacity of the pool ljzdckvm002.cn.prod-local-
9a21555e id: 139 is (99.95 GB) 107321753600
2023-07-05 12:49:36,962 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) orches
trating VM start for 's-30807-VM' com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-07-05 12:49:36,966 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Successfully set Capacity - (99.95 GB) 107321753600 for capacity type
- 9 , DataCenterId - 10, HostOrPoolId - 139, PodId 9
2023-07-05 12:49:36,977 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Found storage pool ljzdckvm005.cn.prod-local-572e5d2c of type Filesyst
em with overprovisioning factor 2
2023-07-05 12:49:36,977 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Total over provisioned capacity calculated is 2 * (49.98 GB) 536608768
00
2023-07-05 12:49:36,977 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Total over provisioned capacity of the pool ljzdckvm005.cn.prod-local-
572e5d2c id: 152 is (99.95 GB) 107321753600
2023-07-05 12:49:36,990 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Successfully set Capacity - (99.95 GB) 107321753600 for capacity type
- 9 , DataCenterId - 11, HostOrPoolId - 152, PodId 10
2023-07-05 12:49:36,992 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) VM instance
{id: "30807", name: "s-30807-VM", uuid: "5934da82-a444-4417-9e50-c98b43e5f295", type="SecondaryStorageVm"} state transited from [Stopped] to [Starting] with ev
ent [StartRequested]. VM's original host: null, new host: null, host before state transition: null
2023-07-05 12:49:36,992 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Succes
sfully transitioned to start state for VM instance {id: "30807", name: "s-30807-VM", uuid: "5934da82-a444-4417-9e50-c98b43e5f295", type="SecondaryStorageVm"} r
eservation id = 781a62c3-45f1-4571-b603-fda24f27da6a
2023-07-05 12:49:37,002 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Found storage pool tj-ps-cloudstack_wq of type RBD with overprovisioni
ng factor 2
2023-07-05 12:49:37,002 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Total over provisioned capacity calculated is 2 * (2.4414 TB) 26843335
88480
2023-07-05 12:49:37,002 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Total over provisioned capacity of the pool tj-ps-cloudstack_wq id: 15
3 is (4.8828 TB) 5368667176960
2023-07-05 12:49:37,003 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Successfully set Capacity - (4.8828 TB) 5368667176960 for capacity typ
e - 3 , DataCenterId - 11, HostOrPoolId - 153, PodId null
2023-07-05 12:49:37,015 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Found storage pool ljzdckvm006.cn.prod-local-95739121 of type Filesyst
em with overprovisioning factor 2
2023-07-05 12:49:37,015 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Total over provisioned capacity calculated is 2 * (49.98 GB) 536608768
00
2023-07-05 12:49:37,015 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Total over provisioned capacity of the pool ljzdckvm006.cn.prod-local-
95739121 id: 154 is (99.95 GB) 107321753600
2023-07-05 12:49:37,018 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Deploy
avoids pods: null, clusters: null, hosts: null
2023-07-05 12:49:37,023 DEBUG [c.c.s.StorageManagerImpl] (HTTP-Dispatcher:null) (logid:) Successfully set Capacity - (99.95 GB) 107321753600 for capacity type
- 9 , DataCenterId - 11, HostOrPoolId - 154, PodId 10
2023-07-05 12:49:37,023 DEBUG [c.c.a.AlertManagerImpl] (HTTP-Dispatcher:null) (logid:) Done executing storage capacity update
2023-07-05 12:49:37,023 DEBUG [c.c.a.AlertManagerImpl] (HTTP-Dispatcher:null) (logid:) Executing capacity updates for public ip and Vlans
2023-07-05 12:49:37,030 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) VM sta
rt attempt #1
2023-07-05 12:49:37,037 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) De
ploymentPlanner allocation algorithm: null
2023-07-05 12:49:37,037 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Tr
ying to allocate a host and storage pools from dc:9, pod:null,cluster:null, requested cpu: 1000, requested ram: (8.00 GB) 8589934592
2023-07-05 12:49:37,037 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Is
ROOT volume READY (pool already allocated)?: No
2023-07-05 12:49:37,078 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) De
ploy avoids pods: [], clusters: [], hosts: null
2023-07-05 12:49:37,211 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) VM instance
{id: "30807", name: "s-30807-VM", uuid: "5934da82-a444-4417-9e50-c98b43e5f295", type="SecondaryStorageVm"} state transited from [Starting] to [Stopped] with ev
ent [OperationFailed]. VM's original host: null, new host: null, host before state transition: null
2023-07-05 12:49:37,213 WARN [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Unable
to orchestrate start VM instance {id: "30807", name: "s-30807-VM", uuid: "5934da82-a444-4417-9e50-c98b43e5f295", type="SecondaryStorageVm"} due to [Unable to
create deployment, no usable volumes found for the VM: 30807].
com.cloud.utils.exception.CloudRuntimeException: Unable to create deployment, no usable volumes found for the VM: 30807
at com.cloud.deploy.DeploymentPlanningManagerImpl.findSuitablePoolsForVolumes(DeploymentPlanningManagerImpl.java:1569)
at com.cloud.deploy.DeploymentPlanningManagerImpl.checkClustersforDestination(DeploymentPlanningManagerImpl.java:1217)
at com.cloud.deploy.DeploymentPlanningManagerImpl.planDeployment(DeploymentPlanningManagerImpl.java:527)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1126)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5315)
at jdk.internal.reflect.GeneratedMethodAccessor1073.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5439)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
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:829)
2023-07-05 12:49:37,215 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Done execu
ting VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":30807,"handlerName":"VirtualMachineManagerImpl"}
2023-07-05 12:49:37,217 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Comple
te async job-111727, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NF
cnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAA
FY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cH
ByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AONVbmFibGUgdG8gb3JjaGVzdHJhdGUgc3RhcnQgVk0gaW5zdGFuY2Uge2lkOiAiMzA4MDciLCBuYW1lOiAicy0zMDgwNy1WTSIsI
HV1aWQ6ICI1OTM0ZGE4Mi1hNDQ0LTQ0MTctOWU1MC1jOThiNDNlNWYyOTUiLCB0eXBlPSJTZWNvbmRhcnlTdG9yYWdlVm0ifSBkdWUgdG8gW1VuYWJsZSB0byBjcmVhdGUgZGVwbG95bWVudCwgbm8gdXNhYmxl
IHZvbHVtZXMgZm91bmQgZm9yIHRoZSBWTTogMzA4MDddLnVyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAAE3NyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcW
aJjbdhQIACEIABmZvcm1hdEkACmxpbmVOdW1iZXJMAA9jbGFzc0xvYWRlck5hbWVxAH4ABUwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFTAAKbW9kdWxlTm
FtZXEAfgAFTAANbW9kdWxlVmVyc2lvbnEAfgAFeHABAAAUx3QAA2FwcHQAJmNvbS5jbG91ZC52bS5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsdAAeVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbC5qYXZhdAAQb
3JjaGVzdHJhdGVTdGFydHBwc3EAfgAMAP____9wdAAwamRrLmludGVybmFsLnJlZmxlY3QuR2VuZXJhdGVkTWV0aG9kQWNjZXNzb3IxMDczcHQABmludm9rZXBwc3EAfgAMAgAAACtwdAAxamRrLmludGVybmFs
LnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAUdAAJamF2YS5iYXNldAAHMTEuMC4xOXNxAH4ADAIAAAI2cHQAGGphdmE
ubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABRxAH4AGHEAfgAZc3EAfgAMAQAAAGtxAH4ADnQAImNvbS5jbG91ZC52bS5WbVdvcmtKb2JIYW5kbGVyUHJveHl0ABpWbVdvcmtKb2JIYW5kbG
VyUHJveHkuamF2YXQAD2hhbmRsZVZtV29ya0pvYnBwc3EAfgAMAQAAFT9xAH4ADnEAfgAPcQB-ABBxAH4AIHBwc3EAfgAMAQAAAGZxAH4ADnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYV
m1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9icHBzcQB-AAwBAAACbHEAfgAOdAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAY
QXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0cHBzcQB-AAwBAAAAMHEAfgAOdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmx
lJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5wcHNxAH4ADAEAAAA3cQB-AA50AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb2
50ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxwcHNxAH4ADAEAAABmcQB-AA50AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZ
WRDb250ZXh0cQB-ADB0AA9jYWxsV2l0aENvbnRleHRwcHNxAH4ADAEAAAA0cQB-AA5xAH4AM3EAfgAwdAAOcnVuV2l0aENvbnRleHRwcHNxAH4ADAEAAAAtcQB-AA50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2su
bWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4ALHEAfgAtcHBzcQB-AAwBAAACOHEAfgAOcQB-ACdxAH4AKHEAfgAtcHBzcQB-AAwCAAACA3B0AC5qYXZhLnV0aWwuY29uY3VycmVudC5
FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4AMXEAfgAYcQB-ABlzcQB-AAwCAAABCHB0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGFzay5qYX
ZhcQB-AC1xAH4AGHEAfgAZc3EAfgAMAgAABGhwdAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJxAH4AGHEAfgAZc
3EAfgAMAgAAAnRwdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgBCcQB-AC1xAH4AGHEAfgAZc3EAfgAMAgAAAz1wdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVh
ZC5qYXZhcQB-AC1xAH4AGHEAfgAZc3IAH2phdmEudXRpbC5Db2xsZWN0aW9ucyRFbXB0eUxpc3R6uBe0PKee3gIAAHhweAAAEJp3CAAAAAAAAAAAeA
2023-07-05 12:49:37,225 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Publis
h async job-111727 complete on message bus
2023-07-05 12:49:37,225 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-155:ctx-91480b0f job-111384/job-111727 ctx-5869ebdb) (logid:3d9f0ff3) Wake u
p jobs related to job-111727
Please give some advices？
xuanyuanaosheng
commented
1 year ago @rajujith @weizhouapache @DaanHoogland
The management-server log is:
Cloud you please help to handle this issue ? If need more info, please add a comment
DaanHoogland
commented
1 year ago @xuanyuanaosheng by the looks of that first stack trace I can only think of the uuid being already used in the DB. Can you check that?
xuanyuanaosheng
commented
1 year ago @xuanyuanaosheng by the looks of that first stack trace I can only think of the uuid being already used in the DB. Can you check that?
@DaanHoogland Which table that the uuid being already used in the DB?
DaanHoogland
commented
1 year ago 2023-07-05 11:35:05,292 WARN [c.c.v.SystemVmLoadScanner] (secstorage-1:ctx-7f6d0d0a) (logid:079dbd17) Unexpected exception DB Exception on: com.mysql.cj.jdbc.ClientPreparedStatement: INSERT INTO nics (nics.instance_id, nics.ip4_address, nics.ip6_address, nics.netmask, nics.isolation_uri, nics.ip_type, nics.broadcast_uri, nics.gateway, nics.mac_address, nics.mode, nics.network_id, nics.state, nics.reserver_name, nics.reservation_id, nics.device_id, nics.update_time, nics.default_nic, nics.ip6_gateway, nics.ip6_cidr, nics.strategy, nics.vm_type, nics.created, nics.uuid, nics.secondary_ip) VALUES (30807, x'31302E37302E33332E3838', null, x'3235352E3235352E3235352E30', 'vlan://2333', 'Ip4', 'vlan://2333', x'31302E37302E33332E323534', x'31653A30303A64323A30303A30303A3330', 'Dhcp', 243, 'Allocated', x'4469726563744E6574776F726B47757275', null, 2, null, 1, null, null, 'Create', 'SecondaryStorageVm', '2023-07-05 03:35:05', x'61303865323563302D383438312D346636652D386566372D623839353838643164613536', 0) com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.cj.jdbc.ClientPreparedStatement: INSERT INTO nics (nics.instance_id, nics.ip4_address, nics.ip6_address, nics.netmask, nics.isolation_uri, nics.ip_type, nics.broadcast_uri, nics.gateway, nics.mac_address, nics.mode, nics.network_id, nics.state, nics.reserver_name, nics.reservation_id, nics.device_id, nics.update_time, nics.default_nic, nics.ip6_gateway, nics.ip6_cidr, nics.strategy, nics.vm_type, nics.created, nics.uuid, nics.secondary_ip) VALUES (30807, x'31302E37302E33332E3838', null, x'3235352E3235352E3235352E30', 'vlan://2333', 'Ip4', 'vlan://2333', x'31302E37302E33332E323534', x'31653A30303A64323A30303A30303A3330', 'Dhcp', 243, 'Allocated', x'4469726563744E6574776F726B47757275', null, 2, null, 1, null, nu ll, 'Create', 'SecondaryStorageVm', '2023-07-05 03:35:05', x'61303865323563302D383438312D346636652D386566372D623839353838643164613536', 0) at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1461) at jdk.internal.reflect.GeneratedMethodAccessor75.invoke(Unknown Source) 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:97) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) at com.sun.proxy.$Proxy70.persist(Unknown Source) at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.allocateNic(NetworkOrchestrator.java:997) at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator$3.addRequestedNicToNicListWithDeviceNumberAndRetrieveDefaultDevice(NetworkOrchestrato r.java:823) at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator$3.doInTransactionWithoutResult(NetworkOrchestrator.java:797)
It seems it is a nics.uuid
harikrishna-patnala
commented
1 year ago @xuanyuanaosheng I think this will solve your issue https://docs.cloudstack.apache.org/en/latest/upgrading/upgrade/mysql.html#mysql-upgrade-problems
ALTER TABLE nics MODIFY COLUMN update_time timestamp DEFAULT CURRENT_TIMESTAMP;
xuanyuanaosheng
commented
1 year ago @harikrishna-patnala Thanks. It has worked.
@DaanHoogland Thanks you. It has worked.
Thanks all of you.
ISSUE TYPE
COMPONENT NAME
SUMMARY
The Secondary storage may be become null when the cloudstack upgrade.
STEPS TO REPRODUCE
The web error is:
The related issue:
I reinstall the template:
The template is
i did as https://github.com/apache/cloudstack/issues/7474 , I changed the databases table
vm_templateandtemplate_store_refThe database infoI destroy the System VMs and wait the System VMs auto start. But the System VMs still can not started as expected.