[
https://issues.apache.org/jira/browse/CLOUDSTACK-8196?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14304608#comment-14304608
]
Abhinandan Prateek commented on CLOUDSTACK-8196:
------------------------------------------------
Errors in SMLog:
ock: closed /var/lock/sm/f89b7dbb-f8af-fbcf-4dbc-13f7c921d151/sr
Jan 31 22:25:56 xen652 SM: [4038] lock: closed
/var/lock/sm/f89b7dbb-f8af-fbcf-4dbc-13f7c921d151/running
Jan 31 22:28:38 xen652 SM: [3617] Warning: vdi_[de]activate present for dummy
Jan 31 22:28:44 xen652 SM: [3907] sr_attach {'sr_uuid':
'30334f48-a747-4024-792b-f34741c5280f', 'subtask_of':
'DummyRef:|7aafcf09-7437-db39-d8b7-38e84a3c2f43|SR.attach', 'args': [],
'host_ref': 'OpaqueRef:9fe68e4b-6e5f-854a-cb22-7c6ee30ea9fc', 'session_ref':
'OpaqueRef:45efeeac-20d8-6eda-454c-7a8326152ec0', 'device_config':
{'legacy_mode': 'true', 'SRmaster': 'true', 'location':
'/opt/xensource/packages/iso'}, 'command': 'sr_attach', 'sr_ref':
'OpaqueRef:adfba5ae-fab1-37fd-911b-f7ebd3ce2168'}
Jan 31 22:28:44 xen652 SM: [3907] lock: opening lock file
/var/lock/sm/30334f48-a747-4024-792b-f34741c5280f/running
Jan 31 22:28:44 xen652 SM: [3907] lock: opening lock file
/var/lock/sm/30334f48-a747-4024-792b-f34741c5280f/sr
Jan 31 22:28:44 xen652 SM: [3907] lock: acquired
/var/lock/sm/30334f48-a747-4024-792b-f34741c5280f/running
Jan 31 22:28:44 xen652 SM: [3907] lock: acquired
/var/lock/sm/30334f48-a747-4024-792b-f34741c5280f/sr
Jan 31 22:28:44 xen652 SM: [3907] RESET for SR
30334f48-a747-4024-792b-f34741c5280f (master: True)
Jan 31 22:28:44 xen652 SM: [3907] lock: released
/var/lock/sm/30334f48-a747-4024-792b-f34741c5280f/sr
Jan 31 22:28:44 xen652 SM: [3907] lock: released
/var/lock/sm/30334f48-a747-4024-792b-f34741c5280f/running
Jan 31 22:28:44 xen652 SM: [3907] lock: closed
/var/lock/sm/30334f48-a747-4024-792b-f34741c5280f/sr
Jan 31 22:28:44 xen652 SM: [3907] lock: closed
/var/lock/sm/30334f48-a747-4024-792b-f34741c5280f/running
Jan 31 22:28:44 xen652 SM: [3907] set_dirty
'OpaqueRef:adfba5ae-fab1-37fd-911b-f7ebd3ce2168' succeeded
Jan 31 22:28:51 xen652 SM: [4062] lock: opening lock file
/var/lock/sm/d3e92b9d-1ae5-616c-aa17-dc22edb614e6/sr
Jan 31 22:28:51 xen652 SM: [4062] LVMCache created for
VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6
Jan 31 22:28:51 xen652 SM: [4062] ['/usr/sbin/vgs',
'VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6']
Jan 31 22:28:51 xen652 SM: [4062] FAILED in util.pread: (rc 5) stdout: '',
stderr: ' Volume group "VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6"
not found
Jan 31 22:28:51 xen652 SM: [4062] '
Jan 31 22:28:51 xen652 SM: [4062] LVMCache: will initialize now
Jan 31 22:28:51 xen652 SM: [4062] LVMCache: refreshing
Jan 31 22:28:51 xen652 SM: [4062] ['/usr/sbin/lvs', '--noheadings', '--units',
'b', '-o', '+lv_tags',
'/dev/VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6']
Jan 31 22:28:52 xen652 SM: [4062] FAILED in util.pread: (rc 5) stdout: '',
stderr: ' Volume group "VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6"
not found
Jan 31 22:28:52 xen652 SM: [4062] Skipping volume group
VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6
Jan 31 22:28:52 xen652 SM: [4062] '
Jan 31 22:28:52 xen652 SM: [4062] lock: acquired
/var/lock/sm/d3e92b9d-1ae5-616c-aa17-dc22edb614e6/sr
Jan 31 22:28:52 xen652 SM: [4062] sr_create {'sr_uuid':
'd3e92b9d-1ae5-616c-aa17-dc22edb614e6', 'subtask_of':
'DummyRef:|31b63d40-5758-e196-bb11-f7ec74ea21b3|SR.create', 'args': ['0'],
'host_ref': 'OpaqueRef:9fe68e4b-6e5f-854a-cb22-7c6ee30ea9fc', 'session_ref':
'OpaqueRef:349d0349-4b73-2464-c776-eee3b2119f68', 'device_config': {'device':
'/dev/sda3', 'SRmaster': 'true'}, 'command': 'sr_create', 'sr_ref':
'OpaqueRef:073078b0-c6cd-d897-a2c4-42cc35d1c71d'}
Jan 31 22:28:52 xen652 SM: [4062] LVHDSR.create for
d3e92b9d-1ae5-616c-aa17-dc22edb614e6
Jan 31 22:28:52 xen652 SM: [4062] ['/usr/sbin/vgs',
'VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6']
Jan 31 22:28:52 xen652 SM: [4062] FAILED in util.pread: (rc 5) stdout: '',
stderr: ' Volume group "VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6"
not found
Jan 31 22:28:52 xen652 SM: [4062] '
Jan 31 22:28:52 xen652 SM: [4062] ['sginfo', '-s', '/dev/sda3']
Jan 31 22:28:52 xen652 SM: [4062] pread SUCCESS
Jan 31 22:28:52 xen652 SM: [4062] ['scsi_id', '-g', '--device', '/dev/sda']
Jan 31 22:28:52 xen652 SM: [4062] FAILED in util.pread: (rc 1) stdout: '',
stderr: 'scsi_id: invalid option -- -
Jan 31 22:28:52 xen652 SM: [4062] '
Jan 31 22:28:52 xen652 SM: [4062] ['scsi_id', '-g', '--device', '/dev/sda']
failed with ('Operation not permitted',)
Jan 31 22:28:52 xen652 SM: [4062] ['scsi_id', '-g', '-s', '/block/sda']
Jan 31 22:28:52 xen652 SM: [4062] FAILED in util.pread: (rc 1) stdout: '',
stderr: ''
Jan 31 22:28:52 xen652 SM: [4062] ['scsi_id', '-g', '-s', '/block/sda'] failed
with ('Operation not permitted',)
Jan 31 22:28:52 xen652 SM: [4062] util.test_scsiserial: Unable to verify serial
or SCSIid of device: /dev/sda3
Jan 31 22:28:52 xen652 SM: [4062] ['/bin/dd', 'if=/dev/zero', 'of=/dev/sda3',
'bs=1M', 'count=10', 'oflag=direct']
Jan 31 22:28:52 xen652 SM: [4062] pread SUCCESS
Jan 31 22:28:52 xen652 SM: [4062] ['/usr/sbin/pvcreate', '--metadatasize',
'10M', '/dev/sda3']
Jan 31 22:28:52 xen652 SM: [4062] pread SUCCESS
Jan 31 22:28:52 xen652 SM: [4062] ['/usr/sbin/vgcreate',
'VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6', '/dev/sda3']
Jan 31 22:28:52 xen652 SM: [4062] pread SUCCESS
Jan 31 22:28:52 xen652 SM: [4062] ['/usr/sbin/vgchange', '-an', '--master',
'VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6']
Jan 31 22:28:52 xen652 SM: [4062] pread SUCCESS
Jan 31 22:28:52 xen652 SM: [4062] ['scsi_id', '-g', '--device', '/dev/sda']
Jan 31 22:28:52 xen652 SM: [4062] FAILED in util.pread: (rc 1) stdout: '',
stderr: 'scsi_id: invalid option -- -
Jan 31 22:28:52 xen652 SM: [4062] '
Jan 31 22:28:52 xen652 SM: [4062] ['scsi_id', '-g', '--device', '/dev/sda']
failed with ('Operation not permitted',)
Jan 31 22:28:52 xen652 SM: [4062] ['scsi_id', '-g', '-s', '/block/sda']
Jan 31 22:28:52 xen652 SM: [4062] FAILED in util.pread: (rc 1) stdout: '',
stderr: ''
Jan 31 22:28:52 xen652 SM: [4062] ['scsi_id', '-g', '-s', '/block/sda'] failed
with ('Operation not permitted',)
Jan 31 22:28:52 xen652 SM: [4062] lock: released
/var/lock/sm/d3e92b9d-1ae5-616c-aa17-dc22edb614e6/sr
Jan 31 22:28:52 xen652 SM: [4062] lock: closed
/var/lock/sm/d3e92b9d-1ae5-616c-aa17-dc22edb614e6/sr
Jan 31 22:28:52 xen652 SM: [4095] lock: opening lock file
/var/lock/sm/d3e92b9d-1ae5-616c-aa17-dc22edb614e6/sr
Jan 31 22:28:52 xen652 SM: [4095] LVMCache created for
VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6
Jan 31 22:28:52 xen652 SM: [4095] ['/usr/sbin/vgs',
'VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6']
Jan 31 22:28:52 xen652 SM: [4095] pread SUCCESS
Jan 31 22:28:52 xen652 SM: [4095] lock: acquired
/var/lock/sm/d3e92b9d-1ae5-616c-aa17-dc22edb614e6/sr
Jan 31 22:28:52 xen652 SM: [4095] LVMCache: will initialize now
Jan 31 22:28:52 xen652 SM: [4095] LVMCache: refreshing
Jan 31 22:28:52 xen652 SM: [4095] ['/usr/sbin/lvs', '--noheadings', '--units',
'b', '-o', '+lv_tags',
'/dev/VG_XenStorage-d3e92b9d-1ae5-616c-aa17-dc22edb614e6']
Jan 31 22:28:52 xen652 SM: [4095] pread SUCCESS
Jan 31 22:28:52 xen652 SM: [4095] lock: released
/var/lock/sm/d3e92b9d-1ae5-616c-aa17-dc22edb614e6/sr
Jan 31 22:28:52 xen652 SM: [4095] lock: acquired
/var/lock/sm/d3e92b9d-1ae5-616c-aa17-dc22edb614e6/sr
Jan 31 22:28:52 xen652 SM: [4095] sr_attach {'sr_uuid':
'd3e92b9d-1ae5-616c-aa17-dc22edb614e6', 'subtask_of':
'DummyRef:|e6bee5f4-4147-cffb-94bc-e7eba5f6b54f|SR.attach', 'args': [],
'host_ref': 'OpaqueRef:9fe68e4b-6e5f-854a-cb22-7c6ee30ea9fc', 'sessi
> Local storage - Live VM migration fails
> ---------------------------------------
>
> Key: CLOUDSTACK-8196
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-8196
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Volumes
> Affects Versions: 4.5.0
> Environment: Xenserver 6.5
> Reporter: Abhinandan Prateek
> Priority: Blocker
> Fix For: 4.5.0
>
>
> When you live migrate a VM with its root volume on local storage it fails
> with following in the logs:
> 2015-02-03 17:41:17,697 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Executing AsyncJobVO {id:30,
> userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd:
> com.cloud.vm.VmWorkMigrate, cmdInfo:
> rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAAEdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAQdwgAAAAQAAAAAHg,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
> null, initMsid: 345043735628, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: Tue Feb 03 17:41:16 IST 2015}
> 2015-02-03 17:41:17,698 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Run VM work job:
> com.cloud.vm.VmWorkMigrate for VM 4, job origin: 29
> 2015-02-03 17:41:17,699 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Execute VM work
> job:
> com.cloud.vm.VmWorkMigrateWithStorage{"srcHostId":1,"destHostId":4,"volumeToPool":{},"userId":2,"accountId":2,"vmId":4,"handlerName":"VirtualMachineManagerImpl"}
> 2015-02-03 17:41:17,699 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-821cceb5) Zone 1 is ready to launch secondary storage VM
> 2015-02-03 17:41:17,706 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611)
> LocalStoragePoolAllocator trying to find storage pool to fit the vm
> 2015-02-03 17:41:17,710 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Checking if
> storage pool is suitable, name: null ,poolId: 2
> 2015-02-03 17:41:17,712 INFO [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Storage pool
> null (2) does not supply IOPS capacity, assuming enough capacity
> 2015-02-03 17:41:17,714 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Checking pool 2
> for storage, totalSize: 34347155456, usedBytes: 4194304, usedPct:
> 1.2211503236048357E-4, disable threshold: 0.99
> 2015-02-03 17:41:17,718 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Found storage
> pool xen652 Local Storage of type LVM
> 2015-02-03 17:41:17,718 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Total capacity
> of the pool xen652 Local Storage id: 2 is 34347155456
> 2015-02-03 17:41:17,718 DEBUG [c.c.s.StorageManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Checking pool:
> 2 for volume allocation [Vol[4|vm=4|ROOT]], maxSize : 34347155456,
> totalAllocatedSize : 0, askingSize : 0, allocated disable threshold: 0.99
> 2015-02-03 17:41:17,718 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Found suitable
> local storage pool 2, adding to list
> 2015-02-03 17:41:17,718 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611)
> LocalStoragePoolAllocator returning 1 suitable storage pools
> 2015-02-03 17:41:17,719 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611)
> ClusterScopeStoragePoolAllocator looking for storage pool
> 2015-02-03 17:41:17,719 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611)
> ZoneWideStoragePoolAllocator to find storage pool
> 2015-02-03 17:41:17,723 DEBUG [c.c.n.NetworkModelImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Service
> SecurityGroup is not supported in the network id=204
> 2015-02-03 17:41:17,726 DEBUG [o.a.c.e.o.VolumeOrchestrator]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Preparing 1
> volumes for VM[User|i-2-4-VM]
> 2015-02-03 17:41:17,747 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) VM state
> transitted from :Running to Migrating with event: MigrationRequestedvm's
> original host id: 1 new host id: 4 host id before state transition: 1
> 2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Hosts's actual
> total CPU: 6382 and CPU after applying overprovisioning: 25528
> 2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) We are
> allocating VM, increasing the used capacity of this host:4
> 2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Current Used
> CPU: 0 , Free CPU:25528 ,Requested CPU: 500
> 2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Current Used
> RAM: 0 , Free RAM:3266390016 ,Requested RAM: 134217728
> 2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) CPU STATS after
> allocation: for host: 4, old used: 0, old reserved: 0, actual total: 6382,
> total with overprovisioning: 25528; new used:500, reserved:0; requested
> cpu:500,alloc_from_last:false
> 2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) RAM STATS after
> allocation: for host: 4, old used: 0, old reserved: 0, total: 3266390016; new
> used: 134217728, reserved: 0; requested mem: 134217728,alloc_from_last:false
> 2015-02-03 17:41:17,777 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-656ffab6) Zone 1 is ready to launch console proxy
> 2015-02-03 17:41:17,785 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
> 4-379428268605964298: Sending { Cmd , MgmtId: 345043735628, via: 4(xen652),
> Ver: v1, Flags: 100111,
> [{"com.cloud.agent.api.MigrateWithStorageCommand":{"vm":{"id":4,"name":"i-2-4-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS
> 5.6 (64-bit)","platformEmulator":"CentOS 5
> (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":true,"vncPassword":"2M0FMXjOhAukbg729Jj05Q==","params":{"memoryOvercommitRatio":"1.0","platform":"viridian:true;acpi:1;apic:true;pae:true;nx:true","cpuOvercommitRatio":"4.0","hypervisortoolsversion":"xenserver56"},"uuid":"e9b86cce-fdc2-4b26-bb6e-322118f30ddf","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cfae7b2b-d019-414a-8332-b87a59577392","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"70d1dc4e-b70c-0b44-9f87-794905e5863d","id":1,"poolType":"LVM","host":"192.168.217.12","path":"lvm","port":0,"url":"LVM://192.168.217.12/lvm/?ROLE=Primary&STOREUUID=70d1dc4e-b70c-0b44-9f87-794905e5863d"}},"name":"ROOT-4","size":21474836480,"path":"b2baca19-68e9-4b11-8091-48f95f11e9c7","volumeId":4,"vmName":"i-2-4-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":4,"deviceId":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"b2baca19-68e9-4b11-8091-48f95f11e9c7","type":"ROOT","_details":{"managed":"false","storagePort":"0","storageHost":"192.168.217.12","volumeSize":"21474836480"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":-1,"defaultNic":true,"pxeDisable":false,"nicUuid":"d868298c-70ce-4523-a61e-4d201a091d9f","uuid":"198d58c3-333b-43f1-92d1-7163a6207059","ip":"10.1.1.132","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:39:b9:00:02","dns1":"192.168.100.1","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://646","isolationUri":"vlan://646","isSecurityGroupEnabled":false,"name":"GUEST"}],"vcpuMaxLimit":16},"volumeToFiler":{"Vol[4|ROOT|b2baca19-68e9-4b11-8091-48f95f11e9c7|21474836480]":{"id":2,"uuid":"d3e92b9d-1ae5-616c-aa17-dc22edb614e6","host":"192.168.217.14","path":"lvm","port":0,"type":"LVM"}},"wait":0}}]
> }
> 2015-02-03 17:41:17,786 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
> 4-379428268605964298: Executing: { Cmd , MgmtId: 345043735628, via:
> 4(xen652), Ver: v1, Flags: 100111,
> [{"com.cloud.agent.api.MigrateWithStorageCommand":{"vm":{"id":4,"name":"i-2-4-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS
> 5.6 (64-bit)","platformEmulator":"CentOS 5
> (64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":true,"vncPassword":"2M0FMXjOhAukbg729Jj05Q==","params":{"memoryOvercommitRatio":"1.0","platform":"viridian:true;acpi:1;apic:true;pae:true;nx:true","cpuOvercommitRatio":"4.0","hypervisortoolsversion":"xenserver56"},"uuid":"e9b86cce-fdc2-4b26-bb6e-322118f30ddf","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cfae7b2b-d019-414a-8332-b87a59577392","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"70d1dc4e-b70c-0b44-9f87-794905e5863d","id":1,"poolType":"LVM","host":"192.168.217.12","path":"lvm","port":0,"url":"LVM://192.168.217.12/lvm/?ROLE=Primary&STOREUUID=70d1dc4e-b70c-0b44-9f87-794905e5863d"}},"name":"ROOT-4","size":21474836480,"path":"b2baca19-68e9-4b11-8091-48f95f11e9c7","volumeId":4,"vmName":"i-2-4-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":4,"deviceId":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"b2baca19-68e9-4b11-8091-48f95f11e9c7","type":"ROOT","_details":{"managed":"false","storagePort":"0","storageHost":"192.168.217.12","volumeSize":"21474836480"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":-1,"defaultNic":true,"pxeDisable":false,"nicUuid":"d868298c-70ce-4523-a61e-4d201a091d9f","uuid":"198d58c3-333b-43f1-92d1-7163a6207059","ip":"10.1.1.132","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:39:b9:00:02","dns1":"192.168.100.1","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://646","isolationUri":"vlan://646","isSecurityGroupEnabled":false,"name":"GUEST"}],"vcpuMaxLimit":16},"volumeToFiler":{"Vol[4|ROOT|b2baca19-68e9-4b11-8091-48f95f11e9c7|21474836480]":{"id":2,"uuid":"d3e92b9d-1ae5-616c-aa17-dc22edb614e6","host":"192.168.217.14","path":"lvm","port":0,"type":"LVM"}},"wait":0}}]
> }
> 2015-02-03 17:41:17,786 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-47:ctx-d9cdee8c) Seq 4-379428268605964298: Executing request
> 2015-02-03 17:41:17,838 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-47:ctx-d9cdee8c) SR retrieved for
> d3e92b9d-1ae5-616c-aa17-dc22edb614e6
> 2015-02-03 17:41:17,843 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-47:ctx-d9cdee8c) Checking d3e92b9d-1ae5-616c-aa17-dc22edb614e6
> or SR d3e92b9d-1ae5-616c-aa17-dc22edb614e6 on
> XS[2df4562d-5f47-4345-9fed-95da6b798b45-192.168.217.14]
> 2015-02-03 17:41:19,879 DEBUG [c.c.a.ApiServlet]
> (1369188023@qtp-2043850624-13:ctx-2054c360) ===START=== 192.168.100.30 --
> GET
> command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945678234
> 2015-02-03 17:41:19,896 DEBUG [c.c.a.ApiServlet]
> (1369188023@qtp-2043850624-13:ctx-2054c360 ctx-2341000e) ===END===
> 192.168.100.30 -- GET
> command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945678234
> 2015-02-03 17:41:21,092 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-2:null) SeqA 2-248: Processing Seq 2-248: { Cmd ,
> MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-02-03 17:41:21,096 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-2:null) SeqA 2-248: Sending Seq 2-248: { Ans: ,
> MgmtId: 345043735628, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-02-03 17:41:21,691 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-66d27604) Begin cleanup expired async-jobs
> 2015-02-03 17:41:21,694 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-66d27604) End cleanup expired async-jobs
> 2015-02-03 17:41:22,881 DEBUG [c.c.a.ApiServlet]
> (1369188023@qtp-2043850624-13:ctx-ab1c5d96) ===START=== 192.168.100.30 --
> GET
> command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945681235
> 2015-02-03 17:41:22,900 DEBUG [c.c.a.ApiServlet]
> (1369188023@qtp-2043850624-13:ctx-ab1c5d96 ctx-2593d89e) ===END===
> 192.168.100.30 -- GET
> command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945681235
> 2015-02-03 17:41:25,885 DEBUG [c.c.a.ApiServlet]
> (1369188023@qtp-2043850624-13:ctx-427870e5) ===START=== 192.168.100.30 --
> GET
> command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945684238
> 2015-02-03 17:41:25,894 DEBUG [c.c.a.ApiServlet]
> (1369188023@qtp-2043850624-13:ctx-427870e5 ctx-5d7c65ce) ===END===
> 192.168.100.30 -- GET
> command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945684238
> 2015-02-03 17:41:25,898 WARN [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-47:ctx-d9cdee8c) Task failed! Task record: uuid:
> 80e2ab71-fa8d-ebbd-fdae-3edb3657f459
> nameLabel: Async.VM.migrate_send
> nameDescription:
> allowedOperations: []
> currentOperations: {}
> created: Sat Jan 31 11:38:59 IST 2015
> finished: Sat Jan 31 11:39:07 IST 2015
> status: failure
> residentOn: com.xensource.xenapi.Host@50b4f213
> progress: 1.0
> type: <none/>
> result:
> errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
> otherConfig: {}
> subtaskOf: com.xensource.xenapi.Task@aaf13f6f
> subtasks: []
> 2015-02-03 17:41:25,904 WARN [c.c.h.x.r.XenServer610Resource]
> (DirectAgent-47:ctx-d9cdee8c) Catch Exception
> com.xensource.xenapi.Types$BadAsyncResult. Storage motion failed due to Task
> failed! Task record: uuid:
> 80e2ab71-fa8d-ebbd-fdae-3edb3657f459
> nameLabel: Async.VM.migrate_send
> nameDescription:
> allowedOperations: []
> currentOperations: {}
> created: Sat Jan 31 11:38:59 IST 2015
> finished: Sat Jan 31 11:39:07 IST 2015
> status: failure
> residentOn: com.xensource.xenapi.Host@50b4f213
> progress: 1.0
> type: <none/>
> result:
> errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
> otherConfig: {}
> subtaskOf: com.xensource.xenapi.Task@aaf13f6f
> subtasks: []
> Task failed! Task record: uuid:
> 80e2ab71-fa8d-ebbd-fdae-3edb3657f459
> nameLabel: Async.VM.migrate_send
> nameDescription:
> allowedOperations: []
> currentOperations: {}
> created: Sat Jan 31 11:38:59 IST 2015
> finished: Sat Jan 31 11:39:07 IST 2015
> status: failure
> residentOn: com.xensource.xenapi.Host@50b4f213
> progress: 1.0
> type: <none/>
> result:
> errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
> otherConfig: {}
> subtaskOf: com.xensource.xenapi.Task@aaf13f6f
> subtasks: []
> at
> com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
> 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
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> 2015-02-03 17:41:25,910 DEBUG [c.c.h.x.r.XenServer610Resource]
> (DirectAgent-47:ctx-d9cdee8c) Unable to destroy task
> com.xensource.xenapi.Task@75fb5c on host 2df4562d-5f47-4345-9fed-95da6b798b45
> due to You gave an invalid object reference. The object may have recently
> been deleted. The class parameter gives the type of reference given, and the
> handle parameter echoes the bad value given.
> 2015-02-03 17:41:25,910 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-47:ctx-d9cdee8c) Seq 4-379428268605964298: Response Received:
> 2015-02-03 17:41:25,910 DEBUG [c.c.a.t.Request] (DirectAgent-47:ctx-d9cdee8c)
> Seq 4-379428268605964298: Processing: { Ans: , MgmtId: 345043735628, via: 4,
> Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.MigrateWithStorageAnswer":{"result":false,"details":"Exception:
> com.xensource.xenapi.Types$BadAsyncResult\nMessage: null\nStack: Task
> failed! Task record: uuid:
> 80e2ab71-fa8d-ebbd-fdae-3edb3657f459\n nameLabel:
> Async.VM.migrate_send\n nameDescription: \n allowedOperations: []\n
> currentOperations: {}\n created: Sat Jan 31 11:38:59 IST 2015\n
> finished: Sat Jan 31 11:39:07 IST 2015\n status:
> failure\n residentOn: com.xensource.xenapi.Host@50b4f213\n
> progress: 1.0\n type: <none/>\n result: \n
> errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]\n
> otherConfig: {}\n subtaskOf: com.xensource.xenapi.Task@aaf13f6f\n
> subtasks: []\n\n\tat
> com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)\n\tat
>
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)\n\tat
>
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)\n\tat
>
> com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)\n\tat
>
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)\n\tat
>
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)\n\tat
>
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)\n\tat
>
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)\n\tat
>
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)\n\tat
>
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)\n\tat
>
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)\n\tat
> java.util.concurrent.FutureTask.run(FutureTask.java:262)\n\tat
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)\n\tat
>
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)\n\tat
>
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)\n\tat
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
> java.lang.Thread.run(Thread.java:745)\n","wait":0}}] }
> 2015-02-03 17:41:25,910 DEBUG [c.c.a.m.AgentAttache]
> (DirectAgent-47:ctx-d9cdee8c) Seq 4-379428268605964298: No more commands found
> 2015-02-03 17:41:25,910 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
> 4-379428268605964298: Received: { Ans: , MgmtId: 345043735628, via: 4, Ver:
> v1, Flags: 110, { MigrateWithStorageAnswer } }
> 2015-02-03 17:41:25,910 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Migration with
> storage of vm VM[User|i-2-4-VM] failed. Details: Exception:
> com.xensource.xenapi.Types$BadAsyncResult
> Message: null
> Stack: Task failed! Task record: uuid:
> 80e2ab71-fa8d-ebbd-fdae-3edb3657f459
> nameLabel: Async.VM.migrate_send
> nameDescription:
> allowedOperations: []
> currentOperations: {}
> created: Sat Jan 31 11:38:59 IST 2015
> finished: Sat Jan 31 11:39:07 IST 2015
> status: failure
> residentOn: com.xensource.xenapi.Host@50b4f213
> progress: 1.0
> type: <none/>
> result:
> errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
> otherConfig: {}
> subtaskOf: com.xensource.xenapi.Task@aaf13f6f
> subtasks: []
> at
> com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
> 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
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> 2015-02-03 17:41:25,911 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) copy failed
> com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm
> VM[User|i-2-4-VM] to host Host[-4-Routing]. Exception:
> com.xensource.xenapi.Types$BadAsyncResult
> Message: null
> Stack: Task failed! Task record: uuid:
> 80e2ab71-fa8d-ebbd-fdae-3edb3657f459
> nameLabel: Async.VM.migrate_send
> nameDescription:
> allowedOperations: []
> currentOperations: {}
> created: Sat Jan 31 11:38:59 IST 2015
> finished: Sat Jan 31 11:39:07 IST 2015
> status: failure
> residentOn: com.xensource.xenapi.Host@50b4f213
> progress: 1.0
> type: <none/>
> result:
> errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
> otherConfig: {}
> subtaskOf: com.xensource.xenapi.Task@aaf13f6f
> subtasks: []
> at
> com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
> 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
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> at
> org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.migrateVmWithVolumesWithinCluster(XenServerStorageMotionStrategy.java:211)
> at
> org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.copyAsync(XenServerStorageMotionStrategy.java:115)
> at
> org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:90)
> at
> org.apache.cloudstack.storage.volume.VolumeServiceImpl.migrateVolumes(VolumeServiceImpl.java:1156)
> at
> org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:986)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2169)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4493)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
> at
> com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4596)
> at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:536)
> 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:493)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> 2015-02-03 17:41:25,920 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Unsupported
> data object (VOLUME,
> org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@739ed156), no
> need to delete from object in store ref table
> 2015-02-03 17:41:25,920 DEBUG [o.a.c.e.o.VolumeOrchestrator]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Failed to
> migrated vm VM[User|i-2-4-VM] along with its volumes.
> com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm
> VM[User|i-2-4-VM] to host Host[-4-Routing]. Exception:
> com.xensource.xenapi.Types$BadAsyncResult
> Message: null
> Stack: Task failed! Task record: uuid:
> 80e2ab71-fa8d-ebbd-fdae-3edb3657f459
> nameLabel: Async.VM.migrate_send
> nameDescription:
> allowedOperations: []
> currentOperations: {}
> created: Sat Jan 31 11:38:59 IST 2015
> finished: Sat Jan 31 11:39:07 IST 2015
> status: failure
> residentOn: com.xensource.xenapi.Host@50b4f213
> progress: 1.0
> type: <none/>
> result:
> errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
> otherConfig: {}
> subtaskOf: com.xensource.xenapi.Task@aaf13f6f
> subtasks: []
> at
> com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
> 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
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> 2015-02-03 17:41:25,920 INFO [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Migration was
> unsuccessful. Cleaning up: VM[User|i-2-4-VM]
> 2015-02-03 17:41:25,922 WARN [o.a.c.alerts]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) alertType:: 17
> // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: Unable to
> migrate vm i-2-4-VM from host xen651 in zone ZoneA and pod ZoneA
> 2015-02-03 17:41:25,928 DEBUG [c.c.a.m.AgentAttache]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
> 4-379428268605964299: Routed from 345043735628
> 2015-02-03 17:41:25,929 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
> 4-379428268605964299: Sending { Cmd , MgmtId: 345043735628, via: 4(xen652),
> Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-4-VM","wait":0}}]
> }
> 2015-02-03 17:41:25,929 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
> 4-379428268605964299: Executing: { Cmd , MgmtId: 345043735628, via:
> 4(xen652), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-4-VM","wait":0}}]
> }
> 2015-02-03 17:41:25,929 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-24:ctx-aa18b608) Seq 4-379428268605964299: Executing request
> 2015-02-03 17:41:25,938 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) VM state
> transitted from :Migrating to Running with event: OperationFailedvm's
> original host id: 1 new host id: 1 host id before state transition: 4
> 2015-02-03 17:41:25,947 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-24:ctx-aa18b608) Seq 4-379428268605964299: Response Received:
> 2015-02-03 17:41:25,947 DEBUG [c.c.a.t.Request] (DirectAgent-24:ctx-aa18b608)
> Seq 4-379428268605964299: Processing: { Ans: , MgmtId: 345043735628, via: 4,
> Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not
> exist","wait":0}}] }
> 2015-02-03 17:41:25,947 DEBUG [c.c.a.m.AgentAttache]
> (DirectAgent-24:ctx-aa18b608) Seq 4-379428268605964299: Unable to find
> listener.
> 2015-02-03 17:41:25,950 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Hosts's actual
> total CPU: 6382 and CPU after applying overprovisioning: 25528
> 2015-02-03 17:41:25,950 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Hosts's actual
> total RAM: 3266390144 and RAM after applying overprovisioning: 3266390016
> 2015-02-03 17:41:25,950 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) release cpu
> from host: 4, old used: 500,reserved: 0, actual total: 6382, total with
> overprovisioning: 25528; new used: 0,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
> 2015-02-03 17:41:25,950 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) release mem
> from host: 4, old used: 134217728,reserved: 0, total: 3266390016; new used:
> 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2015-02-03 17:41:25,956 ERROR [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Invocation
> exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Failed
> to migrated vm VM[User|i-2-4-VM] along with its volumes.
> 2015-02-03 17:41:25,956 INFO [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Rethrow
> exception com.cloud.utils.exception.CloudRuntimeException: Failed to migrated
> vm VM[User|i-2-4-VM] along with its volumes.
> 2015-02-03 17:41:25,956 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Done with run of VM work
> job: com.cloud.vm.VmWorkMigrate for VM 4, job origin: 29
> 2015-02-03 17:41:25,957 ERROR [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Unable to complete
> AsyncJobVO {id:30, userId: 2, accountId: 2, instanceType: null, instanceId:
> null, cmd: com.cloud.vm.VmWorkMigrate, cmdInfo:
> rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAAEdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAQdwgAAAAQAAAAAHg,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
> null, initMsid: 345043735628, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: Tue Feb 03 17:41:16 IST 2015}, job origin:29
> com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm
> VM[User|i-2-4-VM] along with its volumes.
> at
> org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:991)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2169)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4493)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
> at
> com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4596)
> at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:536)
> 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:493)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> 2015-02-03 17:41:25,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Complete async job-30,
> jobStatus: FAILED, resultCode: 0, result:
> rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AEBGYWlsZWQgdG8gbWlncmF0ZWQgdm0gVk1bVXNlcnxpLTItNC1WTV0gYWxvbmcgd2l0aCBpdHMgdm9sdW1lcy4gdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAWc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFeHAAAAPfdAA9b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmVuZ2luZS5vcmNoZXN0cmF0aW9uLlZvbHVtZU9yY2hlc3RyYXRvcnQAF1ZvbHVtZU9yY2hlc3RyYXRvci5qYXZhdAAObWlncmF0ZVZvbHVtZXNzcQB-AAwAAAh5dAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AB1vcmNoZXN0cmF0ZU1pZ3JhdGVXaXRoU3RvcmFnZXNxAH4ADAAAEY1xAH4AEnEAfgATcQB-ABRzcQB-AAz____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgAMAAAAOXEAfgAXcQB-ABh0AAZpbnZva2VzcQB-AAwAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAbc3EAfgAMAAACXnQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABtzcQB-AAwAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgAMAAAR9HEAfgAScQB-ABNxAH4AJXNxAH4ADAAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADAAAAhh0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAwAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAwAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgAMAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4ANXQAD2NhbGxXaXRoQ29udGV4dHNxAH4ADAAAADVxAH4AOHEAfgA1dAAOcnVuV2l0aENvbnRleHRzcQB-AAwAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADFxAH4AMnNxAH4ADAAAAe1xAH4ALHEAfgAtcQB-ADJzcQB-AAwAAAHXdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADZzcQB-AAwAAAEGdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAyc3EAfgAMAAAEeXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAMAAACZ3QALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AR3EAfgAyc3EAfgAMAAAC6XQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAyc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AU3gAABCadwgAAAAAAAAAAHg
> 2015-02-03 17:41:25,970 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Publish async job-30
> complete on message bus
> 2015-02-03 17:41:25,970 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Wake up jobs related to
> job-30
> 2015-02-03 17:41:25,970 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Update db status for job-30
> 2015-02-03 17:41:25,972 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Wake up jobs joined with
> job-30 and disjoin all subjobs created from job- 30
> 2015-02-03 17:41:25,998 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Done executing
> com.cloud.vm.VmWorkMigrate for job-30
> 2015-02-03 17:41:25,999 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Sync queue (4) is currently
> empty
> 2015-02-03 17:41:26,000 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Remove job-30 from job
> monitoring
> 2015-02-03 17:41:26,009 ERROR [c.c.a.ApiAsyncJobDispatcher]
> (API-Job-Executor-17:ctx-d145a559 job-29) Unexpected exception while
> executing
> org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd
> com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm
> VM[User|i-2-4-VM] along with its volumes.
> at
> org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:991)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2169)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4493)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
> at
> com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4596)
> at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:536)
> 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:493)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> 2015-02-03 17:41:26,011 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-17:ctx-d145a559 job-29) Complete async job-29, jobStatus:
> FAILED, resultCode: 530, result:
> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed
> to migrated vm VM[User|i-2-4-VM] along with its volumes. "}
> 2015-02-03 17:41:26,012 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-17:ctx-d145a559 job-29) Publish async job-29 complete on
> message bus
> 2015-02-03 17:41:26,012 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-17:ctx-d145a559 job-29) Wake up jobs related to job-29
> 2015-02-03 17:41:26,012 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-17:ctx-d145a559 job-29) Update db status for job-29
> 2015-02-03 17:41:26,013 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-17:ctx-d145a559 job-29) Wake up jobs joined with job-29 and
> disjoin all subjobs created from job- 29
> 2015-02-03 17:41:26,017 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-17:ctx-d145a559 job-29) Done executing
> org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd
> for job-29
> 2015-02-03 17:41:26,017 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (API-Job-Executor-17:ctx-d145a559 job-29) Remove job-29 from job monitoring
> 2015-02-03 17:41:28,888 DEBUG [c.c.a.ApiServlet]
> (1369188023@qtp-2043850624-13:ctx-55cb7646) ===START=== 192.168.100.30 --
> GET
> command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945687242
> 2015-02-03 17:41:28,906 DEBUG [c.c.a.ApiServlet]
> (1369188023@qtp-2043850624-13:ctx-55cb7646 ctx-eeffe1a8) ===END===
> 192.168.100.30 -- GET
> command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945687242
> 2015-02-03 17:41:31,091 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-3:null) SeqA 2-249: Processing Seq 2-249: { Cmd ,
> MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-02-03 17:41:31,096 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-3:null) SeqA 2-249: Sending Seq 2-249: { Ans: ,
> MgmtId: 345043735628, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-02-03 17:41:31,691 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-c2a39692) Begin cleanup expired async-jobs
> 2015-02-03 17:41:31,694 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-c2a39692) End cleanup expired async-jobs
> 2015-02-03 17:41:31,721 INFO [c.c.n.v.VpcManagerImpl]
> (VpcChecker-1:ctx-21a431b7) Found 0 removed VPCs to cleanup
> 2015-02-03 17:41:31,759 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-ce1bdd15) Found 1 routers to update status.
> 2015-02-03 17:41:31,759 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-ce1bdd15) Found 0 networks to update RvR status.
> 2015-02-03 17:41:31,864 INFO [c.c.u.AccountManagerImpl]
> (AccountChecker-1:ctx-387c4fa4) Found 0 removed accounts to cleanup
> 2015-02-03 17:41:31,865 INFO [c.c.u.AccountManagerImpl]
> (AccountChecker-1:ctx-387c4fa4) Found 0 disabled accounts to cleanup
> 2015-02-03 17:41:31,865 INFO [c.c.u.AccountManagerImpl]
> (AccountChecker-1:ctx-387c4fa4) Found 0 inactive domains to cleanup
> 2015-02-03 17:41:31,866 INFO [c.c.u.AccountManagerImpl]
> (AccountChecker-1:ctx-387c4fa4) Found 0 disabled projects to cleanup
> 2015-02-03 17:41:36,092 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-4:null) SeqA 2-250: Processing Seq 2-250: { Cmd ,
> MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-02-03 17:41:36,094 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-4:null) SeqA 2-250: Sending Seq 2-250: { Ans: ,
> MgmtId: 345043735628, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-02-03 17:41:37,331 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgentCronJob-12:ctx-c0c8a6a8) Ping from 1(xen651)
> 2015-02-03 17:41:37,332 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-12:ctx-c0c8a6a8) Process host VM state report from ping
> process. host: 1
> 2015-02-03 17:41:37,335 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-12:ctx-c0c8a6a8) Process VM state report. host: 1, number
> of records in report: 4
> 2015-02-03 17:41:37,335 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-12:ctx-c0c8a6a8) VM state report. host: 1, vm id: 1,
> power state: PowerOn
> 2015-02-03 17:41:37,335 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-12:ctx-c0c8a6a8) VM power state does not change, skip DB
> writing. vm id: 1
> 2015-02-03 17:41:37,335 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-12:ctx-c0c8a6a8) VM state report. host: 1, vm id: 2,
> power state: PowerOn
> 2015-02-03 17:41:37,336 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-12:ctx-c0c8a6a8) VM power state does not change, skip DB
> writing. vm id: 2
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
