jonathaanbastin commented on issue #11709:
URL: https://github.com/apache/cloudstack/issues/11709#issuecomment-3328282267
Management server logs:
`2025-09-24 12:43:34,009 DEBUG [c.c.a.ApiServer]
(qtp1438988851-1253:[ctx-aa17de59, ctx-35da8fe0]) (logid:f993d93e) Retrieved
cmdEventType from job info: VM.MIGRATE
2025-09-24 12:43:34,012 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:9fd3ccc6) Add job-3306
into job monitoring
2025-09-24 12:43:34,014 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp1438988851-1253:[ctx-aa17de59, ctx-35da8fe0]) (logid:f993d93e) submit async
job-3306, details: AsyncJob
{"accountId":2,"cmd":"org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd","cmdInfo":"{\"virtualmachineid\":\"51f458fe-5c68-48f3-8d09-4fd76ed92efe\",\"response\":\"json\",\"ctxUserId\":\"2\",\"sessionkey\":\"e8oS1rokaU0Ubu9nFE7WRJKpZfE\",\"hostid\":\"cefc9df8-c2f6-4388-823d-6d1b8980fc88\",\"httpmethod\":\"POST\",\"ctxStartEventId\":\"11817\",\"ctxDetails\":\"{\\\"interface
com.cloud.host.Host\\\":\\\"cefc9df8-c2f6-4388-823d-6d1b8980fc88\\\",\\\"interface
com.cloud.vm.VirtualMachine\\\":\\\"51f458fe-5c68-48f3-8d09-4fd76ed92efe\\\"}\",\"ctxAccountId\":\"2\",\"cmdEventType\":\"VM.MIGRATE\"}","cmdVersion":0,"completeMsid":null,"created":null,"id":3306,"initMsid":345052554317,"instanceId":14849,"instanceType":"VirtualMachine","lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"res
ultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"4b79cff1-eb38-40b9-a613-578b18f7fbc1"}
2025-09-24 12:43:34,014 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Executing
AsyncJob
{"accountId":2,"cmd":"org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd","cmdInfo":"{\"virtualmachineid\":\"51f458fe-5c68-48f3-8d09-4fd76ed92efe\",\"response\":\"json\",\"ctxUserId\":\"2\",\"sessionkey\":\"e8oS1rokaU0Ubu9nFE7WRJKpZfE\",\"hostid\":\"cefc9df8-c2f6-4388-823d-6d1b8980fc88\",\"httpmethod\":\"POST\",\"ctxStartEventId\":\"11817\",\"ctxDetails\":\"{\\\"interface
com.cloud.host.Host\\\":\\\"cefc9df8-c2f6-4388-823d-6d1b8980fc88\\\",\\\"interface
com.cloud.vm.VirtualMachine\\\":\\\"51f458fe-5c68-48f3-8d09-4fd76ed92efe\\\"}\",\"ctxAccountId\":\"2\",\"cmdEventType\":\"VM.MIGRATE\"}","cmdVersion":0,"completeMsid":null,"created":null,"id":3306,"initMsid":345052554317,"instanceId":14849,"instanceType":"VirtualMachine","lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN
_PROGRESS","userId":2,"uuid":"4b79cff1-eb38-40b9-a613-578b18f7fbc1"}
2025-09-24 12:43:34,015 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1253:[ctx-aa17de59, ctx-35da8fe0]) (logid:f993d93e) ===END===
172.31.250.14 -- POST
command=migrateVirtualMachine
response=json
hostid=cefc9df8-c2f6-4388-823d-6d1b8980fc88
virtualmachineid=51f458fe-5c68-48f3-8d09-4fd76ed92efe
sessionkey=e8oS1rokaU0Ubu9nFE7WRJKpZfE
2025-09-24 12:43:34,045 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Host {id: 2, name: frn1-q05-s01, uuid: cefc9df8-c2f6-4388-823d-6d1b8980fc88} is
KVM hypervisor type, no max guest limit check needed
2025-09-24 12:43:34,045 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Checking if there are any ongoing snapshots volumes associated with VM VM
instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Running","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
2025-09-24 12:43:34,046 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Found 1 no. of volumes of type null for vm with VM ID VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Running","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
2025-09-24 12:43:34,047 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Checking status of snapshots for Volume: Volume
{"id":298,"instanceId":14849,"name":"ROOT-14849","uuid":"068ac855-37ef-4246-b65b-9893aa4e8f0c","volumeType":"ROOT"}
2025-09-24 12:43:34,049 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
The count of ongoing Snapshots for VM VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Running","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
and disk type null is 0
2025-09-24 12:43:34,049 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Found no ongoing snapshots on volumes associated with the vm VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Running","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
2025-09-24 12:43:34,050 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Collect vm disk statistics from host before stopping VM
2025-09-24 12:43:34,051 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Wait time setting on com.cloud.agent.api.GetVmDiskStatsCommand is 1800 seconds
2025-09-24 12:43:34,052 DEBUG [c.c.a.m.ClusteredAgentAttache]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Seq 2-1251719221432287676: Routed from 345052554317
2025-09-24 12:43:34,109 DEBUG [c.c.a.t.Request] (AgentManager-Handler-10:[])
(logid:) Seq 17-1251719221432287676: Processing: { Ans: , MgmtId:
345052554317, via: 17, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.GetVmDiskStatsAnswer":{"hostName":"frn1-q05-s02","vmDiskStatsMap":{"i-73-14849-VM":[]},"result":"true","details":"","wait":"0","bypassHostMaintenance":"false"}}]
}
2025-09-24 12:43:34,109 DEBUG [c.c.a.t.Request]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Seq 17-1251719221432287676: Received: { Ans: , MgmtId: 345052554317, via:
17(frn1-q05-s02), Ver: v1, Flags: 10, { GetVmDiskStatsAnswer } }
2025-09-24 12:43:34,109 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Details from executing class com.cloud.agent.api.GetVmDiskStatsCommand:
2025-09-24 12:43:34,109 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Collect vm network statistics from host before stopping Vm
2025-09-24 12:43:34,111 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Wait time setting on com.cloud.agent.api.GetVmNetworkStatsCommand is 1800
seconds
2025-09-24 12:43:34,112 DEBUG [c.c.a.m.ClusteredAgentAttache]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Seq 2-1251719221432287677: Routed from 345052554317
2025-09-24 12:43:34,166 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1113:[ctx-eb23d640]) (logid:927993ab) ===START=== 172.31.250.14
-- GET
jobId=4b79cff1-eb38-40b9-a613-578b18f7fbc1&command=queryAsyncJobResult&response=json&
2025-09-24 12:43:34,166 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1113:[ctx-eb23d640]) (logid:927993ab) Two factor authentication
is already verified for the user 2, so skipping
2025-09-24 12:43:34,169 DEBUG [c.c.a.ApiServer]
(qtp1438988851-1113:[ctx-eb23d640, ctx-c144c274]) (logid:927993ab) CIDRs from
which account 'Account
[{"accountName":"admin","id":2,"uuid":"391b6fa1-528e-11f0-83fe-005056bc244d"}]'
is allowed to perform API calls: 0.0.0.0/0,::/0
2025-09-24 12:43:34,170 INFO [o.a.c.a.DynamicRoleBasedAPIAccessChecker]
(qtp1438988851-1113:[ctx-eb23d640, ctx-c144c274]) (logid:927993ab) Account for
user id 391cd526-528e-11f0-83fe-005056bc244d is Root Admin or Domain Admin, all
APIs are allowed.
2025-09-24 12:43:34,170 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker]
(qtp1438988851-1113:[ctx-eb23d640, ctx-c144c274]) (logid:927993ab) RoleService
is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2025-09-24 12:43:34,170 DEBUG [o.a.c.r.ApiRateLimitServiceImpl]
(qtp1438988851-1113:[ctx-eb23d640, ctx-c144c274]) (logid:927993ab) API rate
limiting is disabled. We will not use ApiRateLimitService.
2025-09-24 12:43:34,190 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1113:[ctx-eb23d640, ctx-c144c274]) (logid:927993ab) ===END===
172.31.250.14 -- GET
jobId=4b79cff1-eb38-40b9-a613-578b18f7fbc1&command=queryAsyncJobResult&response=json&
2025-09-24 12:43:34,204 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:[])
(logid:) Seq 17-1251719221432287677: Processing: { Ans: , MgmtId:
345052554317, via: 17, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.GetVmNetworkStatsAnswer":{"hostName":"frn1-q05-s02","vmNetworkStatsMap":{"i-73-14849-VM":[{"vmName":"i-73-14849-VM","macAddress":"02:04:01:0c:00:01","bytesSent":"(27.80
KB) 28472","bytesReceived":"(192.80 KB)
197424"}]},"result":"true","details":"","wait":"0","bypassHostMaintenance":"false"}}]
}
2025-09-24 12:43:34,205 DEBUG [c.c.a.t.Request]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Seq 17-1251719221432287677: Received: { Ans: , MgmtId: 345052554317, via:
17(frn1-q05-s02), Ver: v1, Flags: 10, { GetVmNetworkStatsAnswer } }
2025-09-24 12:43:34,205 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Details from executing class com.cloud.agent.api.GetVmNetworkStatsCommand:
2025-09-24 12:43:34,207 INFO [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:[ctx-02f731e2]) (logid:b43d5ac3) No inactive management
server node found
2025-09-24 12:43:34,207 DEBUG [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:[ctx-02f731e2]) (logid:b43d5ac3) Peer scan is finished.
profiler: Done. Duration: 1ms , profilerQueryActiveList: Done. Duration: 1ms, ,
profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList:
Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,,
profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms
2025-09-24 12:43:34,219 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306, ctx-eed43438]) (logid:4b79cff1)
Sync job-3307 execution on object VmWorkJobQueue.14849
2025-09-24 12:43:35,706 INFO [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:[ctx-2e70a0f7]) (logid:e6ef1cb8) No inactive management
server node found
2025-09-24 12:43:35,706 DEBUG [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:[ctx-2e70a0f7]) (logid:e6ef1cb8) Peer scan is finished.
profiler: Done. Duration: 1ms , profilerQueryActiveList: Done. Duration: 0ms, ,
profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList:
Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,,
profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms
2025-09-24 12:43:35,948 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$6]
(AsyncJobMgr-Heartbeat-1:[ctx-00a12f0c]) (logid:4fe53b75) Execute sync-queue
item: SyncQueueItemVO {id:1679, queueId: 1514, contentType: AsyncJob,
contentId: 3307, lastProcessMsid: 345052554317, lastprocessNumber: 15,
lastProcessTime: Wed Sep 24 12:43:35 UTC 2025, created: Wed Sep 24 12:43:34 UTC
2025}
2025-09-24 12:43:35,949 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:[ctx-00a12f0c]) (logid:4fe53b75) Schedule queued
job-3307
2025-09-24 12:43:35,952 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:c24ca19f) Add
job-3307 into job monitoring
2025-09-24 12:43:35,954 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1)
Executing AsyncJob
{"accountId":2,"cmd":"com.cloud.vm.VmWorkMigrate","cmdInfo":"rO0ABXNyABpjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZRdxQXtPtzYqAgAGSgAJc3JjSG9zdElkTAAJY2x1c3RlcklkdAAQTGphdmEvbGFuZy9Mb25nO0wABmhvc3RJZHEAfgABTAAFcG9kSWRxAH4AAUwAB3N0b3JhZ2V0AA9MamF2YS91dGlsL01hcDtMAAZ6b25lSWRxAH4AAXhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAA6AXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAEXNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAAAnEAfgAJcQB-AAlwc3EAfgAHAAAAAAAAAAQ","cmdVersion":0,"completeMsid":null,"created":"Wed
Sep 24 12:43:34 UTC
2025","id":3307,"initMsid":345052554317,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":n
ull,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"c4d1b0b1-ce17-484f-9226-baf52639ec70"}
2025-09-24 12:43:35,955 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1) Run
VM work job: com.cloud.vm.VmWorkMigrate for VM 14849, job origin: 3306
2025-09-24 12:43:35,956 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Execute VM work job:
com.cloud.vm.VmWorkMigrate{"zoneId":4,"podId":2,"clusterId":2,"hostId":2,"srcHostId":17,"userId":2,"accountId":2,"vmId":14849,"handlerName":"VirtualMachineManagerImpl"}
2025-09-24 12:43:35,959 INFO [c.c.v.ClusteredVirtualMachineManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Migrating VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Running","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
to
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(4)-Pod(2)-Cluster(2)-Host(2)-Storage()]
2025-09-24 12:43:35,983 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Service SecurityGroup is not supported in the network Network
{"id": 268, "name": "Default", "uuid": "3583e29e-2607-4fb9-ad1f-6bf29fd279d2",
"networkofferingid": 9}
2025-09-24 12:43:36,001 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Service SecurityGroup is not supported in the network Network
{"id": 268, "name": "Default", "uuid": "3583e29e-2607-4fb9-ad1f-6bf29fd279d2",
"networkofferingid": 9}
2025-09-24 12:43:36,016 DEBUG [o.a.c.e.o.VolumeOrchestrator]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Preparing to migrate [1] volumes for VM [VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Running","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}].
2025-09-24 12:43:36,022 DEBUG [o.a.c.e.o.VolumeOrchestrator]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Found [0] snapshots [[]] that have checkpoints for volume with
id [298].
2025-09-24 12:43:36,043 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) template Template {"format":"ISO","id":223,"name":"Debian 12
iso","uniqueName":"223-2-ae701fe6-b1e9-3d5e-a1ce-39037c3acf9b","uuid":"4594e20e-2d61-47ee-a4eb-f5f5ecabeec3"}
with id 223 is already in store:ImageStore
{"id":7,"name":"SC003-SecondaryStorage-P1","uuid":"dcc7ffd0-15f5-4e58-8975-1b4c792792f8"},
type: Image
2025-09-24 12:43:36,100 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Wait time setting on
com.cloud.agent.api.PrepareForMigrationCommand is 1800 seconds
2025-09-24 12:43:36,101 DEBUG [c.c.a.m.ClusteredAgentAttache]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Seq 2-684265668383604931: Routed from 345052554317
2025-09-24 12:43:36,103 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Seq 2-684265668383604931: Sending { Cmd , MgmtId:
345052554317, via: 2(frn1-q05-s01), Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.PrepareForMigrationCommand":{"vm":{"id":"14849","name":"i-73-14849-VM","state":"Running","type":"User","cpus":"2","minSpeed":"1","maxSpeed":"3","minRam":"(2.00
GB) 2147483648","maxRam":"(2.00 GB) 2147483648","arch":"x86_64","os":"Debian
GNU/Linux 12 (64-bit)","platformEmulator":"Debian GNU/Linux 12
(64-bit)","bootArgs":"","enableHA":"true","limitCpuUse":"false","enableDynamicallyScaleVm":"false","details":{"cpuNumber":"2","cpuOvercommitRatio":"2.5","rootdisksize":"30","memory":"2048","cpuSpeed":"3"},"uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe","enterHardwareSetup":"false","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"068ac855-37ef-4246-b65b-9893aa4e8f0c","volumeType":"ROOT","dataStore
":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"520f9d4c-f5a2-4279-b830-20327588987c","name":"SC003
Primary1","id":"2","poolType":"SharedMountPoint","host":"localhost","path":"/SC003","port":"0","url":"SharedMountPoint://localhost/SC003/?ROLE=Primary&STOREUUID=520f9d4c-f5a2-4279-b830-20327588987c","isManaged":"false"}},"name":"ROOT-14849","size":"(30.00
GB)
32212254720","path":"068ac855-37ef-4246-b65b-9893aa4e8f0c","volumeId":"298","vmName":"i-73-14849-VM","accountId":"73","format":"QCOW2","provisioningType":"THIN","poolId":"2","id":"298","deviceId":"0","bytesReadRate":"(0
bytes) 0","bytesWriteRate":"(0 bytes) 0","iopsReadRate":"(1000 bytes)
1000","iopsWriteRate":"(1000 bytes)
1000","hypervisorType":"KVM","directDownload":"false","deployAsIs":"false","checkpointPaths":[],"checkpointImageStoreUrls":[],"followRedirects":"false"}},"diskSeq":"0","path":"068ac855-37ef-4246-b65b-9893aa4e8f0c","type":"ROOT","details":{"storageHost":"localhost","managed":"false","storagePo
rt":"0","storage.pool.disk.wait":"60","volumeSize":"(30.00 GB)
32212254720"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/223/223-2-ae701fe6-b1e9-3d5e-a1ce-39037c3acf9b.iso","origUrl":"https://chuangtzu.ftp.acc.umu.se/debian-cd/current/amd64/iso-cd/debian-12.11.0-amd64-netinst.iso","uuid":"4594e20e-2d61-47ee-a4eb-f5f5ecabeec3","id":"223","format":"ISO","accountId":"2","checksum":"{SHA-512}0921d8b297c63ac458d8a06f87cd4c353f751eb5fe30fd0d839ca09c0833d1d9934b02ee14bbd0c0ec4f8917dde793957801ae1af3c8122cdf28dde8f3c3e0da","hvm":"true","displayText":"Debian
12
x64","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.250.211.108/SC003-SecondaryStorage-P1","_role":"Image"}},"name":"223-2-ae701fe6-b1e9-3d5e-a1ce-39037c3acf9b","guestOsType":"Debian
GNU/Linux 12 (64-bit)","size":"(670.00 MB)
702545920","hypervisorType":"None","bootable":"false","uniqueName":"223-2-ae701fe6-b1e9-3d5e-a1ce-39037c3acf9b","directDownload":"false","deployAsIs"
:"false","followRedirects":"false"}},"diskSeq":"3","type":"ISO"}],"nics":[{"deviceId":"0","networkRateMbps":"100","defaultNic":"true","pxeDisable":"false","nicUuid":"f2e3eec6-2024-4f35-9d6f-6b6a35b4431c","details":{"PromiscuousMode":"false","ForgedTransmits":"true","MacLearning":"false","MacAddressChanges":"true"},"dpdkEnabled":"false","networkId":"268","networkSegmentName":"D69-A73-Z4-S268","uuid":"3583e29e-2607-4fb9-ad1f-6bf29fd279d2","ip":"10.1.1.38","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:04:01:0c:00:01","dns1":"185.52.252.2","dns2":"185.52.255.1","broadcastType":"Vxlan","type":"Guest","broadcastUri":"vxlan://5442","isolationUri":"vxlan://5442","securityGroupEnabled":"false","name":"cloudbr0"}],"vcpuMaxLimit":"2","configDriveLabel":"config-2","configDriveLocation":"SECONDARY","guestOsDetails":{},"extraConfig":{},"networkIdToNetworkNameMap":{"268":"D69-A73-Z4-S268"}},"rollback":"false","wait":"0","bypassHostMaintenance":"false"}}]
}
2025-09-24 12:43:36,840 DEBUG [o.a.c.h.H.HAManagerBgPollTask]
(BackgroundTaskPollManager-3:[ctx-57023261]) (logid:74f280c6) HA health check
task is running...
2025-09-24 12:43:37,206 INFO [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:[ctx-06f8da25]) (logid:90a530f2) No inactive management
server node found
2025-09-24 12:43:37,206 DEBUG [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:[ctx-06f8da25]) (logid:90a530f2) Peer scan is finished.
profiler: Done. Duration: 1ms , profilerQueryActiveList: Done. Duration: 0ms, ,
profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList:
Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,,
profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms
2025-09-24 12:43:37,234 DEBUG [c.c.a.t.Request] (AgentManager-Handler-11:[])
(logid:) Seq 2-684265668383604931: Processing: { Ans: , MgmtId: 345052554317,
via: 2, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.PrepareForMigrationAnswer":{"dpdkInterfaceMapping":{},"newVmCpuShares":"2","result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2025-09-24 12:43:37,234 DEBUG [c.c.a.m.ClusteredAgentAttache]
(AgentManager-Handler-11:[]) (logid:) Seq 2-684265668383604931: No more
commands found
2025-09-24 12:43:37,234 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Seq 2-684265668383604931: Received: { Ans: , MgmtId:
345052554317, via: 2(frn1-q05-s01), Ver: v1, Flags: 110, {
PrepareForMigrationAnswer } }
2025-09-24 12:43:37,245 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Migrating","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
state transited from [Running] to [Migrating] with event [MigrationRequested].
VM's original host: Host
{"id":17,"name":"frn1-q05-s02","type":"Routing","uuid":"542b6cb7-ca52-4ef0-b755-6e6ee3b8ca8c"},
new host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"},
host before state transition: Host
{"id":17,"name":"frn1-q05-s02","type":"Routing","uuid":"542b6cb7-ca52-4ef0-b755-6e6ee3b8ca8c"}
2025-09-24 12:43:37,250 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Hosts's actual total CPU: 160000 and CPU after applying
overprovisioning: 400000
2025-09-24 12:43:37,250 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) We are allocating VM, increasing the used capacity of this
host:Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"}
2025-09-24 12:43:37,251 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Current Used CPU: 3 , Free CPU:399997 ,Requested CPU: 6
2025-09-24 12:43:37,251 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Current Used RAM: (1.00 GB) 1073741824 , Free RAM:(373.65 GB)
401199792128 ,Requested RAM: (2.00 GB) 2147483648
2025-09-24 12:43:37,251 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) CPU STATS after allocation: for host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"},
old used: 3, old reserved: 0, actual total: 160000, total with
overprovisioning: 400000; new used: 9, reserved: 0; requested cpu: 6,
alloc_from_last: false
2025-09-24 12:43:37,251 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) RAM STATS after allocation: for host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"},
old used: (1.00 GB) 1073741824, old reserved: (0 bytes) 0, total: (374.65 GB)
402273533952; new used: (3.00 GB) 3221225472, reserved: (0 bytes) 0; requested
mem: (2.00 GB) 2147483648, alloc_from_last: false
2025-09-24 12:43:37,252 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"}
has cpu capability (cpu: 40, speed: 4000 ) to support requested CPU: 2 and
requested speed: 3
2025-09-24 12:43:37,252 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Checking if host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"}
has enough capacity for requested CPU: 6 and requested RAM: (2.00 GB)
2147483648 , cpuOverprovisioningFactor: 2.5
2025-09-24 12:43:37,253 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Hosts's actual total CPU: 160000 and CPU after applying
overprovisioning: 400000
2025-09-24 12:43:37,253 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) We need to allocate to the last host again, so checking if
there is enough reserved capacity
2025-09-24 12:43:37,253 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Reserved CPU: 0 , Requested CPU: 6
2025-09-24 12:43:37,253 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Reserved RAM: (0 bytes) 0 , Requested RAM: (2.00 GB) 2147483648
2025-09-24 12:43:37,253 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) STATS: Failed to alloc resource from host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"}
reservedCpu: 0, requested cpu: 6, reservedMem: (0 bytes) 0, requested mem:
(2.00 GB) 2147483648
2025-09-24 12:43:37,253 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Host does not have enough reserved CPU available, cannot
allocate to this host.
2025-09-24 12:43:37,253 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Checking if host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"}
has enough capacity for requested CPU: 6 and requested RAM: (2.00 GB)
2147483648 , cpuOverprovisioningFactor: 2.5
2025-09-24 12:43:37,254 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Hosts's actual total CPU: 160000 and CPU after applying
overprovisioning: 400000
2025-09-24 12:43:37,254 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Free CPU: 399997 , Requested CPU: 6
2025-09-24 12:43:37,254 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Free RAM: (373.65 GB) 401199792128 , Requested RAM: (2.00 GB)
2147483648
2025-09-24 12:43:37,254 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Host has enough CPU and RAM available
2025-09-24 12:43:37,254 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) STATS: Can alloc CPU from host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"},
used: 3, reserved: 0, actual total: 160000, total with overprovisioning:
400000; requested cpu: 6, alloc_from_last_host?: false,
considerReservedCapacity?: true
2025-09-24 12:43:37,254 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) STATS: Can alloc MEM from host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"},
used: (1.00 GB) 1073741824, reserved: (0 bytes) 0, total: (374.65 GB)
402273533952; requested mem: (2.00 GB) 2147483648, alloc_from_last_host?:
false, considerReservedCapacity?: true
2025-09-24 12:43:37,260 DEBUG [c.c.s.S.StorageCollector]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) StorageCollector is
running...
2025-09-24 12:43:37,267 DEBUG [c.c.h.XenServerGuru]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) We are returning the default
host to execute commands because the command is not of Copy type.
2025-09-24 12:43:37,267 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) Wait time setting on
com.cloud.agent.api.GetStorageStatsCommand is 1800 seconds
2025-09-24 12:43:37,268 DEBUG [c.c.a.m.ClusteredAgentAttache]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) Seq 2-3314930800721396106:
Routed from 345052554317
2025-09-24 12:43:37,269 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Setting VLAN persistence to [{"5442":true}] as part of migrate
command for VM [VM {id: "14849", name: "i-73-14849-VM", uuid:
"51f458fe-5c68-48f3-8d09-4fd76ed92efe", type: "User"}].
2025-09-24 12:43:37,270 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Setting CPU shares to [2] as part of migrate command for VM
[VM {id: "14849", name: "i-73-14849-VM", uuid:
"51f458fe-5c68-48f3-8d09-4fd76ed92efe", type: "User"}].
2025-09-24 12:43:37,270 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Wait time setting on com.cloud.agent.api.MigrateCommand is
1800 seconds
2025-09-24 12:43:37,270 DEBUG [c.c.a.m.ClusteredAgentAttache]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Seq 2-1251719221432287678: Routed from 345052554317
2025-09-24 12:43:37,272 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Seq 17-1251719221432287678: Sending { Cmd , MgmtId:
345052554317, via: 17(frn1-q05-s02), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.MigrateCommand":{"vmName":"i-73-14849-VM","destinationIp":"10.40.10.1","migrateStorageManaged":"false","migrateNonSharedInc":"false","autoConvergence":"true","hostGuid":"da6d7fe4-97f2-3afe-a857-042138192eff-LibvirtComputingResource","windows":"false","virtualMachine":{"id":"14849","name":"i-73-14849-VM","state":"Running","type":"User","cpus":"2","minSpeed":"1","maxSpeed":"3","minRam":"(2.00
GB) 2147483648","maxRam":"(2.00 GB) 2147483648","arch":"x86_64","os":"Debian
GNU/Linux 12 (64-bit)","platformEmulator":"Debian GNU/Linux 12
(64-bit)","bootArgs":"","enableHA":"true","limitCpuUse":"false","enableDynamicallyScaleVm":"false","details":{"cpuNumber":"2","cpuOvercommitRatio":"2.5","rootdisksize":"30","memory":"2048"
,"cpuSpeed":"3"},"uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe","enterHardwareSetup":"false","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"068ac855-37ef-4246-b65b-9893aa4e8f0c","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"520f9d4c-f5a2-4279-b830-20327588987c","name":"SC003
Primary1","id":"2","poolType":"SharedMountPoint","host":"localhost","path":"/SC003","port":"0","url":"SharedMountPoint://localhost/SC003/?ROLE=Primary&STOREUUID=520f9d4c-f5a2-4279-b830-20327588987c","isManaged":"false"}},"name":"ROOT-14849","size":"(30.00
GB)
32212254720","path":"068ac855-37ef-4246-b65b-9893aa4e8f0c","volumeId":"298","vmName":"i-73-14849-VM","accountId":"73","format":"QCOW2","provisioningType":"THIN","poolId":"2","id":"298","deviceId":"0","bytesReadRate":"(0
bytes) 0","bytesWriteRate":"(0 bytes) 0","iopsReadRate":"(1000 bytes)
1000","iopsWriteRate":"(1000 bytes)
1000","hypervisorType":"KVM","directDownload":"false","d
eployAsIs":"false","checkpointPaths":[],"checkpointImageStoreUrls":[],"followRedirects":"false"}},"diskSeq":"0","path":"068ac855-37ef-4246-b65b-9893aa4e8f0c","type":"ROOT","details":{"storageHost":"localhost","managed":"false","storagePort":"0","storage.pool.disk.wait":"60","volumeSize":"(30.00
GB)
32212254720"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/223/223-2-ae701fe6-b1e9-3d5e-a1ce-39037c3acf9b.iso","origUrl":"https://chuangtzu.ftp.acc.umu.se/debian-cd/current/amd64/iso-cd/debian-12.11.0-amd64-netinst.iso","uuid":"4594e20e-2d61-47ee-a4eb-f5f5ecabeec3","id":"223","format":"ISO","accountId":"2","checksum":"{SHA-512}0921d8b297c63ac458d8a06f87cd4c353f751eb5fe30fd0d839ca09c0833d1d9934b02ee14bbd0c0ec4f8917dde793957801ae1af3c8122cdf28dde8f3c3e0da","hvm":"true","displayText":"Debian
12
x64","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.250.211.108/SC003-SecondaryStorage-P1","_role":"Image"}},"name":"223-2-ae701fe6-b1e9-3
d5e-a1ce-39037c3acf9b","guestOsType":"Debian GNU/Linux 12
(64-bit)","size":"(670.00 MB)
702545920","hypervisorType":"None","bootable":"false","uniqueName":"223-2-ae701fe6-b1e9-3d5e-a1ce-39037c3acf9b","directDownload":"false","deployAsIs":"false","followRedirects":"false"}},"diskSeq":"3","type":"ISO"}],"nics":[{"deviceId":"0","networkRateMbps":"100","defaultNic":"true","pxeDisable":"false","nicUuid":"f2e3eec6-2024-4f35-9d6f-6b6a35b4431c","details":{"PromiscuousMode":"false","ForgedTransmits":"true","MacLearning":"false","MacAddressChanges":"true"},"dpdkEnabled":"false","networkId":"268","networkSegmentName":"D69-A73-Z4-S268","uuid":"3583e29e-2607-4fb9-ad1f-6bf29fd279d2","ip":"10.1.1.38","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:04:01:0c:00:01","dns1":"185.52.252.2","dns2":"185.52.255.1","broadcastType":"Vxlan","type":"Guest","broadcastUri":"vxlan://5442","isolationUri":"vxlan://5442","securityGroupEnabled":"false","name":"cloudbr0"}],"vcpuMaxLimit":"2","configDriveLabe
l":"config-2","configDriveLocation":"SECONDARY","guestOsDetails":{},"extraConfig":{},"networkIdToNetworkNameMap":{"268":"D69-A73-Z4-S268"}},"executeInSequence":"false","migrateDiskInfoList":[],"dpdkInterfaceMapping":{},"newVmCpuShares":"2","vlanToPersistenceMap":{"5442":"true"},"wait":"0","bypassHostMaintenance":"false"}}]
}
2025-09-24 12:43:37,277 DEBUG [c.c.a.t.Request] (AgentManager-Handler-13:[])
(logid:) Seq 17-1251719221432287678: Processing: { Ans: , MgmtId:
345052554317, via: 17, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":"false","details":"com.cloud.utils.exception.CloudRuntimeException:
Provided libvirt destination ip is invalid
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.createMigrationURI(LibvirtMigrateCommandWrapper.java:98)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:107)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:88)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1958)
at com.cloud.agent.Agent.processRequest(Agent.java:779)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1194)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
","wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-24 12:43:37,277 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Seq 17-1251719221432287678: Received: { Ans: , MgmtId:
345052554317, via: 17(frn1-q05-s02), Ver: v1, Flags: 10, { Answer } }
2025-09-24 12:43:37,277 INFO [c.c.v.ClusteredVirtualMachineManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Migration was unsuccessful. Cleaning up: VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Migrating","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
2025-09-24 12:43:37,286 DEBUG [o.a.c.e.o.VolumeOrchestrator]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Releasing [1] volumes for VM [VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Migrating","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}]
from host [Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"}].
2025-09-24 12:43:37,288 DEBUG [o.a.c.e.o.VolumeOrchestrator]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Found [0] snapshots [[]] that have checkpoints for volume with
id [298].
2025-09-24 12:43:37,291 WARN [c.c.a.AlertManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) alertType=[17] dataCenterId=[4] podId=[2] clusterId=[null]
message=[Unable to migrate vm i-73-14849-VM from host frn1-q05-s02 in zone
UK-South and pod UK-South-P1].
2025-09-24 12:43:37,298 DEBUG [c.c.a.AlertManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Have already sent: 1 emails for alert type '17' -- skipping
send email
2025-09-24 12:43:37,298 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Migrating","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
is a [User], returning null for control Nic IP.
2025-09-24 12:43:37,305 DEBUG [c.c.a.m.ClusteredAgentAttache]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Seq 2-684265668383604932: Routed from 345052554317
2025-09-24 12:43:37,305 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Seq 2-684265668383604932: Sending { Cmd , MgmtId:
345052554317, via: 2(frn1-q05-s01), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","forceStop":"false","vlanToPersistenceMap":{"5442":"true"},"expungeVM":"false","volumesToDisconnect":[],"vmName":"i-73-14849-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}]
}
2025-09-24 12:43:37,311 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) VM instance
{"id":14849,"instanceName":"i-73-14849-VM","state":"Running","type":"User","uuid":"51f458fe-5c68-48f3-8d09-4fd76ed92efe"}
state transited from [Migrating] to [Running] with event [OperationFailed].
VM's original host: Host
{"id":17,"name":"frn1-q05-s02","type":"Routing","uuid":"542b6cb7-ca52-4ef0-b755-6e6ee3b8ca8c"},
new host: Host
{"id":17,"name":"frn1-q05-s02","type":"Routing","uuid":"542b6cb7-ca52-4ef0-b755-6e6ee3b8ca8c"},
host before state transition: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"}
2025-09-24 12:43:37,314 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Hosts's actual total CPU: 160000 and CPU after applying
overprovisioning: 400000
2025-09-24 12:43:37,314 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Hosts's actual total RAM: (374.65 GB) 402273529856 and RAM
after applying overprovisioning: (374.65 GB) 402273533952
2025-09-24 12:43:37,314 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) release cpu from host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"},
old used: 9, reserved: 0, actual total: 160000, total with overprovisioning:
400000; new used: 3,reserved:0; movedfromreserved: false,moveToReservered: false
2025-09-24 12:43:37,315 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) release mem from host: Host
{"id":2,"name":"frn1-q05-s01","type":"Routing","uuid":"cefc9df8-c2f6-4388-823d-6d1b8980fc88"},
old used: (3.00 GB) 3221225472, reserved: (0 bytes) 0, total: (374.65 GB)
402273533952; new used: (1.00 GB) 1073741824, reserved: (0 bytes) 0;
movedfromreserved: false, moveToReservered: false
2025-09-24 12:43:37,317 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1110:[ctx-038f69c5]) (logid:f72f45fa) ===START=== 172.31.250.14
-- GET
managementserverid=2dac6929-3205-4b64-af06-8710c65f3c01&command=readyForShutdown&response=json&
2025-09-24 12:43:37,317 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1110:[ctx-038f69c5]) (logid:f72f45fa) Two factor authentication
is already verified for the user 2, so skipping
2025-09-24 12:43:37,319 DEBUG [c.c.a.ApiServer]
(qtp1438988851-1110:[ctx-038f69c5, ctx-09a42103]) (logid:f72f45fa) CIDRs from
which account 'Account
[{"accountName":"admin","id":2,"uuid":"391b6fa1-528e-11f0-83fe-005056bc244d"}]'
is allowed to perform API calls: 0.0.0.0/0,::/0
2025-09-24 12:43:37,319 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Invocation exception, caused by:
com.cloud.utils.exception.CloudRuntimeException:
com.cloud.utils.exception.CloudRuntimeException: Provided libvirt destination
ip is invalid
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.createMigrationURI(LibvirtMigrateCommandWrapper.java:98)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:107)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:88)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1958)
at com.cloud.agent.Agent.processRequest(Agent.java:779)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1194)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
2025-09-24 12:43:37,319 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307, ctx-4e3ba99d])
(logid:4b79cff1) Rethrow exception
com.cloud.utils.exception.CloudRuntimeException:
com.cloud.utils.exception.CloudRuntimeException: Provided libvirt destination
ip is invalid
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.createMigrationURI(LibvirtMigrateCommandWrapper.java:98)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:107)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:88)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1958)
at com.cloud.agent.Agent.processRequest(Agent.java:779)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1194)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
2025-09-24 12:43:37,319 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1) Done
with run of VM work job: com.cloud.vm.VmWorkMigrate for VM 14849, job origin:
3306
2025-09-24 12:43:37,319 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1)
Unable to complete AsyncJob
{"accountId":2,"cmd":"com.cloud.vm.VmWorkMigrate","cmdInfo":"rO0ABXNyABpjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZRdxQXtPtzYqAgAGSgAJc3JjSG9zdElkTAAJY2x1c3RlcklkdAAQTGphdmEvbGFuZy9Mb25nO0wABmhvc3RJZHEAfgABTAAFcG9kSWRxAH4AAUwAB3N0b3JhZ2V0AA9MamF2YS91dGlsL01hcDtMAAZ6b25lSWRxAH4AAXhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAA6AXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAEXNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAAAnEAfgAJcQB-AAlwc3EAfgAHAAAAAAAAAAQ","cmdVersion":0,"completeMsid":null,"created":"Wed
Sep 24 12:43:34 UTC
2025","id":3307,"initMsid":345052554317,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":
null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"c4d1b0b1-ce17-484f-9226-baf52639ec70"},
job origin: 3306 com.cloud.utils.exception.CloudRuntimeException:
com.cloud.utils.exception.CloudRuntimeException: Provided libvirt destination
ip is invalid
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.createMigrationURI(LibvirtMigrateCommandWrapper.java:98)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:107)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:88)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1958)
at com.cloud.agent.Agent.processRequest(Agent.java:779)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1194)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
at
com.cloud.vm.VirtualMachineManagerImpl.migrate(VirtualMachineManagerImpl.java:3107)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrate(VirtualMachineManagerImpl.java:2984)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrate(VirtualMachineManagerImpl.java:5854)
at jdk.internal.reflect.GeneratedMethodAccessor690.invoke(Unknown
Source)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5951)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:689)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(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:637)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
2025-09-24 12:43:37,320 INFO [o.a.c.a.DynamicRoleBasedAPIAccessChecker]
(qtp1438988851-1110:[ctx-038f69c5, ctx-09a42103]) (logid:f72f45fa) Account for
user id 391cd526-528e-11f0-83fe-005056bc244d is Root Admin or Domain Admin, all
APIs are allowed.
2025-09-24 12:43:37,320 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker]
(qtp1438988851-1110:[ctx-038f69c5, ctx-09a42103]) (logid:f72f45fa) RoleService
is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2025-09-24 12:43:37,320 DEBUG [o.a.c.r.ApiRateLimitServiceImpl]
(qtp1438988851-1110:[ctx-038f69c5, ctx-09a42103]) (logid:f72f45fa) API rate
limiting is disabled. We will not use ApiRateLimitService.
2025-09-24 12:43:37,322 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1)
Complete async job-3307, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvblZNT3AAAAACAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0BMZjb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbjogUHJvdmlkZWQgbGlidmlydCBkZXN0aW5hdGlvbiBpcCBpcyBpbnZhbGlkCglhdCBjb20uY2xvdWQuaHlwZXJ2aXNvci5rdm0ucmVzb3VyY2Uud3JhcHBlci5MaWJ2aXJ0TWlncmF0ZUNvbW1hbmRXcmFwcGVyLmNyZWF0ZU1pZ3JhdGlvblVSSShMaWJ2aXJ0TWlncmF0ZUNvbW1hbmRXcmFwcGVyLmphdmE6OTgpCglhdCBjb20uY2xvdW
QuaHlwZXJ2aXNvci5rdm0ucmVzb3VyY2Uud3JhcHBlci5MaWJ2aXJ0TWlncmF0ZUNvbW1hbmRXcmFwcGVyLmV4ZWN1dGUoTGlidmlydE1pZ3JhdGVDb21tYW5kV3JhcHBlci5qYXZhOjEwNykKCWF0IGNvbS5jbG91ZC5oeXBlcnZpc29yLmt2bS5yZXNvdXJjZS53cmFwcGVyLkxpYnZpcnRNaWdyYXRlQ29tbWFuZFdyYXBwZXIuZXhlY3V0ZShMaWJ2aXJ0TWlncmF0ZUNvbW1hbmRXcmFwcGVyLmphdmE6ODgpCglhdCBjb20uY2xvdWQuaHlwZXJ2aXNvci5rdm0ucmVzb3VyY2Uud3JhcHBlci5MaWJ2aXJ0UmVxdWVzdFdyYXBwZXIuZXhlY3V0ZShMaWJ2aXJ0UmVxdWVzdFdyYXBwZXIuamF2YTo3OCkKCWF0IGNvbS5jbG91ZC5oeXBlcnZpc29yLmt2bS5yZXNvdXJjZS5MaWJ2aXJ0Q29tcHV0aW5nUmVzb3VyY2UuZXhlY3V0ZVJlcXVlc3QoTGlidmlydENvbXB1dGluZ1Jlc291cmNlLmphdmE6MTk1OCkKCWF0IGNvbS5jbG91ZC5hZ2VudC5BZ2VudC5wcm9jZXNzUmVxdWVzdChBZ2VudC5qYXZhOjc3OSkKCWF0IGNvbS5jbG91ZC5hZ2VudC5BZ2VudCRBZ2VudFJlcXVlc3RIYW5kbGVyLmRvVGFzayhBZ2VudC5qYXZhOjExOTQpCglhdCBjb20uY2xvdWQudXRpbHMubmlvLlRhc2suY2FsbChUYXNrLmphdmE6ODMpCglhdCBjb20uY2xvdWQudXRpbHMubmlvLlRhc2suY2FsbChUYXNrLmphdmE6MjkpCglhdCBqYXZhLmJhc2UvamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFzay5ydW4oRnV0dXJlVGFzay5qYXZhOjI2NCkKCWF
0IGphdmEuYmFzZS9qYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IucnVuV29ya2VyKFRocmVhZFBvb2xFeGVjdXRvci5qYXZhOjExMzYpCglhdCBqYXZhLmJhc2UvamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlci5ydW4oVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmE6NjM1KQoJYXQgamF2YS5iYXNlL2phdmEubGFuZy5UaHJlYWQucnVuKFRocmVhZC5qYXZhOjg0MCkKdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAVc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAIQgAGZm9ybWF0SQAKbGluZU51bWJlckwAD2NsYXNzTG9hZGVyTmFtZXEAfgAFTAAOZGVjbGFyaW5nQ2xhc3NxAH4ABUwACGZpbGVOYW1lcQB-AAVMAAptZXRob2ROYW1lcQB-AAVMAAptb2R1bGVOYW1lcQB-AAVMAA1tb2R1bGVWZXJzaW9ucQB-AAV4cAEAAAwjdAADYXBwdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AAdtaWdyYXRlcHBzcQB-AAwBAAALqHEAfgAOcQB-AA9xAH4AEHQAEm9yY2hlc3RyYXRlTWlncmF0ZXBwc3EAfgAMAQAAFt5xAH4ADnEAfgAPcQB-ABBxAH4AE3Bwc3EAfgAMAP____9wdAAvamRrLmludGVybmFsLnJlZmxlY3QuR2VuZXJhdGVkTWV0aG9kQWNjZXNzb3I2OTBwdAAGaW52b2tlcHBzcQB-AAwCAAAAK3B0ADFqZGsuaW50
ZXJuYWwucmVmbGVjdC5EZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsdAAhRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbC5qYXZhcQB-ABd0AAlqYXZhLmJhc2V0AAcxNy4wLjE2c3EAfgAMAgAAAjlwdAAYamF2YS5sYW5nLnJlZmxlY3QuTWV0aG9kdAALTWV0aG9kLmphdmFxAH4AF3EAfgAbcQB-ABxzcQB-AAwBAAAAZnEAfgAOdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9icHBzcQB-AAwBAAAXP3EAfgAOcQB-AA9xAH4AEHEAfgAjcHBzcQB-AAwBAAAAY3EAfgAOdAAgY29tLmNsb3VkLnZtLlZtV29ya0pvYkRpc3BhdGNoZXJ0ABhWbVdvcmtKb2JEaXNwYXRjaGVyLmphdmF0AAZydW5Kb2JwcHNxAH4ADAEAAAKxcQB-AA50AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRwcHNxAH4ADAEAAAAxcQB-AA50AD5vcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGUkMXQAG01hbmFnZWRDb250ZXh0UnVubmFibGUuamF2YXQAA3J1bnBwc3EAfgAMAQAAADhxAH4ADnQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHQkMXQAGkRlZmF1bHRNYW5hZ2VkQ29ud
GV4dC5qYXZhdAAEY2FsbHBwc3EAfgAMAQAAAGdxAH4ADnQAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AM3QAD2NhbGxXaXRoQ29udGV4dHBwc3EAfgAMAQAAADVxAH4ADnEAfgA2cQB-ADN0AA5ydW5XaXRoQ29udGV4dHBwc3EAfgAMAQAAAC5xAH4ADnQAPG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZXEAfgAvcQB-ADBwcHNxAH4ADAEAAAJ9cQB-AA5xAH4AKnEAfgArcQB-ADBwcHNxAH4ADAIAAAIbcHQALmphdmEudXRpbC5jb25jdXJyZW50LkV4ZWN1dG9ycyRSdW5uYWJsZUFkYXB0ZXJ0AA5FeGVjdXRvcnMuamF2YXEAfgA0cQB-ABtxAH4AHHNxAH4ADAIAAAEIcHQAH2phdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2t0AA9GdXR1cmVUYXNrLmphdmFxAH4AMHEAfgAbcQB-ABxzcQB-AAwCAAAEcHB0ACdqYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3J0ABdUaHJlYWRQb29sRXhlY3V0b3IuamF2YXQACXJ1bldvcmtlcnEAfgAbcQB-ABxzcQB-AAwCAAACe3B0AC5qYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IkV29ya2VycQB-AEVxAH4AMHEAfgAbcQB-ABxzcQB-AAwCAAADSHB0ABBqYXZhLmxhbmcuVGhyZWFkdAALVGhyZWFkLmphdmFxAH4AMHEAfgAbcQB-ABxzcgAfamF2YS51dGlsLkNvbGxlY3Rpb25zJEVtcHR5TGlzdHq4F7
Q8p57eAgAAeHB4AAAQmncIAAAAAAAAAAB4
2025-09-24 12:43:37,323 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1)
Publish async job-3307 complete on message bus
2025-09-24 12:43:37,323 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1) Wake
up jobs related to job-3307
2025-09-24 12:43:37,323 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1)
Update db status for job-3307
2025-09-24 12:43:37,326 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1253:[ctx-60b2bb7f]) (logid:520077ab) ===START=== 172.31.250.14
-- GET
jobId=4b79cff1-eb38-40b9-a613-578b18f7fbc1&command=queryAsyncJobResult&response=json&
2025-09-24 12:43:37,327 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1253:[ctx-60b2bb7f]) (logid:520077ab) Two factor authentication
is already verified for the user 2, so skipping
2025-09-24 12:43:37,327 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1) Wake
up jobs joined with job-3307 and disjoin all subjobs created from job- 3307
2025-09-24 12:43:37,327 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1110:[ctx-038f69c5, ctx-09a42103]) (logid:f72f45fa) ===END===
172.31.250.14 -- GET
managementserverid=2dac6929-3205-4b64-af06-8710c65f3c01&command=readyForShutdown&response=json&
2025-09-24 12:43:37,327 DEBUG [c.c.a.t.Request]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) Seq 19-3314930800721396106:
Received: { Ans: , MgmtId: 345052554317, via: 19(s-14821-VM), Ver: v1, Flags:
10, { GetStorageStatsAnswer } }
2025-09-24 12:43:37,331 DEBUG [c.c.a.ApiServer]
(qtp1438988851-1253:[ctx-60b2bb7f, ctx-b4055db9]) (logid:520077ab) CIDRs from
which account 'Account
[{"accountName":"admin","id":2,"uuid":"391b6fa1-528e-11f0-83fe-005056bc244d"}]'
is allowed to perform API calls: 0.0.0.0/0,::/0
2025-09-24 12:43:37,333 INFO [o.a.c.a.DynamicRoleBasedAPIAccessChecker]
(qtp1438988851-1253:[ctx-60b2bb7f, ctx-b4055db9]) (logid:520077ab) Account for
user id 391cd526-528e-11f0-83fe-005056bc244d is Root Admin or Domain Admin, all
APIs are allowed.
2025-09-24 12:43:37,333 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker]
(qtp1438988851-1253:[ctx-60b2bb7f, ctx-b4055db9]) (logid:520077ab) RoleService
is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2025-09-24 12:43:37,333 DEBUG [o.a.c.r.ApiRateLimitServiceImpl]
(qtp1438988851-1253:[ctx-60b2bb7f, ctx-b4055db9]) (logid:520077ab) API rate
limiting is disabled. We will not use ApiRateLimitService.
2025-09-24 12:43:37,336 DEBUG [c.c.h.XenServerGuru]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) We are returning the default
host to execute commands because the command is not of Copy type.
2025-09-24 12:43:37,336 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) Wait time setting on
com.cloud.agent.api.GetStorageStatsCommand is 1800 seconds
2025-09-24 12:43:37,338 DEBUG [c.c.a.m.ClusteredAgentAttache]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) Seq 2-684265668383604933:
Routed from 345052554317
2025-09-24 12:43:37,339 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1) Done
executing com.cloud.vm.VmWorkMigrate for job-3307
2025-09-24 12:43:37,341 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-46:[ctx-93e03760, job-3306/job-3307]) (logid:4b79cff1)
Remove job-3307 from job monitoring
2025-09-24 12:43:37,350 DEBUG [c.c.a.ApiServlet]
(qtp1438988851-1253:[ctx-60b2bb7f, ctx-b4055db9]) (logid:520077ab) ===END===
172.31.250.14 -- GET
jobId=4b79cff1-eb38-40b9-a613-578b18f7fbc1&command=queryAsyncJobResult&response=json&
2025-09-24 12:43:37,356 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Unexpected
exception while executing
org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd
com.cloud.utils.exception.CloudRuntimeException:
com.cloud.utils.exception.CloudRuntimeException: Provided libvirt destination
ip is invalid
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.createMigrationURI(LibvirtMigrateCommandWrapper.java:98)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:107)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:88)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1958)
at com.cloud.agent.Agent.processRequest(Agent.java:779)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1194)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
at
com.cloud.vm.VirtualMachineManagerImpl.migrate(VirtualMachineManagerImpl.java:3107)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrate(VirtualMachineManagerImpl.java:2984)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrate(VirtualMachineManagerImpl.java:5854)
at jdk.internal.reflect.GeneratedMethodAccessor690.invoke(Unknown
Source)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5951)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:689)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(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:637)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
2025-09-24 12:43:37,357 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Complete async
job-3306, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"530","errortext":"com.cloud.utils.exception.CloudRuntimeException:
Provided libvirt destination ip is invalid
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.createMigrationURI(LibvirtMigrateCommandWrapper.java:98)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:107)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtMigrateCommandWrapper.execute(LibvirtMigrateCommandWrapper.java:88)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1958)
at com.cloud.agent.Agent.processRequest(Agent.java:779)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1194)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
"}
2025-09-24 12:43:37,358 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Publish async
job-3306 complete on message bus
2025-09-24 12:43:37,358 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Wake up jobs
related to job-3306
2025-09-24 12:43:37,358 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Update db
status for job-3306
2025-09-24 12:43:37,358 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Wake up jobs
joined with job-3306 and disjoin all subjobs created from job- 3306
2025-09-24 12:43:37,361 DEBUG [c.c.a.ApiServer]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Retrieved
cmdEventType from job info: VM.MIGRATE
2025-09-24 12:43:37,363 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Done executing
org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd for job-3306
2025-09-24 12:43:37,364 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-49:[ctx-525e132d, job-3306]) (logid:4b79cff1) Remove job-3306
from job monitoring
2025-09-24 12:43:37,549 DEBUG [c.c.a.t.Request] (AgentManager-Handler-2:[])
(logid:) Seq 2-684265668383604932: Processing: { Ans: , MgmtId: 345052554317,
via: 2, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2025-09-24 12:43:37,549 DEBUG [c.c.a.m.ClusteredAgentAttache]
(AgentManager-Handler-2:[]) (logid:) Seq 2-684265668383604932: Unable to find
listener.
2025-09-24 12:43:38,350 DEBUG [c.c.s.S.DbCollector]
(StatsCollector-6:[ctx-1d7c113c]) (logid:560d0623) DbCollector is running...
2025-09-24 12:43:38,422 DEBUG [c.c.a.t.Request]
(StatsCollector-4:[ctx-3ce087b3]) (logid:ff6b37b6) Seq 2-684265668383604933:
Received: { Ans: , MgmtId: 345052554317, via: 2(frn1-q05-s01), Ver: v1, Flags:
10, { GetStorageStatsAnswer } }
2025-09-24 12:43:38,558 DEBUG [c.c.n.r.V.CheckRouterTask]
(RouterStatusMonitor-1:[ctx-80194dee]) (logid:1ee4421e) Found 3 routers to
update status.
2025-09-24 12:43:38,559 DEBUG [c.c.n.r.V.CheckRouterTask]
(RouterStatusMonitor-1:[ctx-80194dee]) (logid:1ee4421e) Found 0 VPC's to update
Redundant State.
2025-09-24 12:43:38,560 DEBUG [c.c.n.r.V.CheckRouterTask]
(RouterStatusMonitor-1:[ctx-80194dee]) (logid:1ee4421e) Found 0 networks to
update RvR status.
2025-09-24 12:43:38,706 INFO [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:[ctx-86ac1732]) (logid:44f7c90e) No inactive management
server node found
2025-09-24 12:43:38,706 DEBUG [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:[ctx-86ac1732]) (logid:44f7c90e) Peer scan is finished.
profiler: Done. Duration: 1ms , profilerQueryActiveList: Done. Duration: 0ms, ,
profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList:
Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,,
profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms`
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
