[ovirt-users] Re: Unable to do Live Migration

Thursday, 28 June 2018


Hello,

for my issue, her we go:
vdsm.log source
2018-06-28 12:25:47,566+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:25:47,575+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:25:48,926+0200 INFO  (jsonrpc/0) [vdsm.api] START
migrate(params={u'incomingLimit': 2, u'src': u'10.157.8.40',
u'dstqemu': u'192.168.1.113', u'autoConverge': u'false',
u'tunneled': u'false', u'enableGuestEvents': False,
u'dst': u'10.157.8.42:54321', u'vmId':
u'a54af7cd-3b89-43c1-82b3-ae0c08d103d3', u'abortOnError': u'true',
u'outgoingLimit': 2, u'compressed': u'false',
u'maxBandwidth': 500, u'method': u'online', 'mode':
'remote'}) from=::ffff:10.157.8.36,53170,
flow_id=db7c94d5-7e11-43b0-95d8-a9095e4f8e83 (api:46)
2018-06-28 12:25:48,929+0200 INFO  (jsonrpc/0) [vdsm.api] FINISH migrate
return={'status': {'message': 'Migration in progress',
'code': 0}, 'progress': 0} from=::ffff:10.157.8.36,53170,
flow_id=db7c94d5-7e11-43b0-95d8-a9095e4f8e83 (api:52)
2018-06-28 12:25:48,930+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call VM.migrate
succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:25:49,153+0200 INFO  (jsonrpc/7) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=554b6d96-89b0-4ff5-a2de-ced7f268d58c (api:46)
2018-06-28 12:25:49,154+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000299843', 'lastCheck': '2.4', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000570989', 'lastCheck': '5.2', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000248445', 'lastCheck': '5.3', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000408845', 'lastCheck': '4.9', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=554b6d96-89b0-4ff5-a2de-ced7f268d58c (api:52)
2018-06-28 12:25:49,173+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:25:49,860+0200 INFO  (migsrc/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Creation of destination VM took: 0
seconds (migration:455)
2018-06-28 12:25:49,861+0200 INFO  (migsrc/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') starting migration to
qemu+tls://10.157.8.42/system with miguri tcp://192.168.1.113 (migration:480)
2018-06-28 12:25:52,080+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:25:55,836+0200 INFO  (periodic/7090) [vdsm.api] START
repoStats(options=None) from=internal, task_id=07d6e59b-93a7-46ef-8ffe-a9b8d8f1d3b1
(api:46)
2018-06-28 12:25:55,837+0200 INFO  (periodic/7090) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000349569', 'lastCheck': '5.3', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000632803', 'lastCheck': '1.8', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.00025132', 'lastCheck': '2.0', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000334113', 'lastCheck': '1.6', 'valid': True}}
from=internal, task_id=07d6e59b-93a7-46ef-8ffe-a9b8d8f1d3b1 (api:52)
2018-06-28 12:25:59,865+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 10 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:26:02,584+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:26:02,610+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:26:04,177+0200 INFO  (jsonrpc/3) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=6226131d-2afb-453f-8fdd-4814985f2602 (api:46)
2018-06-28 12:26:04,177+0200 INFO  (jsonrpc/3) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000240789', 'lastCheck': '3.7', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00048312', 'lastCheck': '0.2', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000303582', 'lastCheck': '0.4', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000334113', 'lastCheck': '3.5', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=6226131d-2afb-453f-8fdd-4814985f2602 (api:52)
2018-06-28 12:26:04,196+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:26:07,142+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:26:09,868+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:26:09,869+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 20 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:26:10,885+0200 INFO  (periodic/7091) [vdsm.api] START
repoStats(options=None) from=internal, task_id=55ee01e0-c474-44ee-a9a5-b1d5fd599043
(api:46)
2018-06-28 12:26:10,885+0200 INFO  (periodic/7091) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000350665', 'lastCheck': '0.3', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00048312', 'lastCheck': '6.9', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000303582', 'lastCheck': '7.1', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000420027', 'lastCheck': '0.2', 'valid': True}}
from=internal, task_id=55ee01e0-c474-44ee-a9a5-b1d5fd599043 (api:52)
2018-06-28 12:26:16,735+0200 INFO  (itmap/0) [IOProcessClient] Starting client
ioprocess-351445 (__init__:330)
2018-06-28 12:26:16,743+0200 INFO  (ioprocess/11232) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,744+0200 INFO  (itmap/1) [IOProcessClient] Starting client
ioprocess-351446 (__init__:330)
2018-06-28 12:26:16,750+0200 INFO  (itmap/2) [IOProcessClient] Starting client
ioprocess-351447 (__init__:330)
2018-06-28 12:26:16,755+0200 INFO  (ioprocess/11240) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,757+0200 INFO  (itmap/3) [IOProcessClient] Starting client
ioprocess-351448 (__init__:330)
2018-06-28 12:26:16,763+0200 INFO  (ioprocess/11247) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,765+0200 INFO  (itmap/4) [IOProcessClient] Starting client
ioprocess-351449 (__init__:330)
2018-06-28 12:26:16,771+0200 INFO  (ioprocess/11256) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,773+0200 INFO  (itmap/5) [IOProcessClient] Starting client
ioprocess-351450 (__init__:330)
2018-06-28 12:26:16,778+0200 INFO  (ioprocess/11265) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,780+0200 INFO  (itmap/6) [IOProcessClient] Starting client
ioprocess-351451 (__init__:330)
2018-06-28 12:26:16,785+0200 INFO  (ioprocess/11275) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,787+0200 INFO  (itmap/7) [IOProcessClient] Starting client
ioprocess-351452 (__init__:330)
2018-06-28 12:26:16,791+0200 INFO  (ioprocess/11283) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,793+0200 INFO  (itmap/8) [IOProcessClient] Starting client
ioprocess-351453 (__init__:330)
2018-06-28 12:26:16,798+0200 INFO  (ioprocess/11290) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,799+0200 INFO  (itmap/9) [IOProcessClient] Starting client
ioprocess-351454 (__init__:330)
2018-06-28 12:26:16,804+0200 INFO  (ioprocess/11297) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,806+0200 INFO  (itmap/10) [IOProcessClient] Starting client
ioprocess-351455 (__init__:330)
2018-06-28 12:26:16,813+0200 INFO  (ioprocess/11304) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,815+0200 INFO  (ioprocess/11311) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:26:16,822+0200 INFO  (monitor/48055e2) [storage.StorageDomain] Resource
namespace 01_img_48055e27-f1ca-466a-8a2c-e191c34f0226 already registered (sd:758)
2018-06-28 12:26:16,822+0200 INFO  (monitor/48055e2) [storage.StorageDomain] Resource
namespace 02_vol_48055e27-f1ca-466a-8a2c-e191c34f0226 already registered (sd:767)
2018-06-28 12:26:17,617+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:26:17,628+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:26:19,199+0200 INFO  (jsonrpc/7) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=13488a51-8f0b-4ea0-89b7-3bc39bb68fa9 (api:46)
2018-06-28 12:26:19,199+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000350665', 'lastCheck': '2.4', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00063241', 'lastCheck': '5.2', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000543002', 'lastCheck': '5.4', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000434669', 'lastCheck': '5.0', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=13488a51-8f0b-4ea0-89b7-3bc39bb68fa9 (api:52)
2018-06-28 12:26:19,218+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:26:19,871+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:26:19,872+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 30 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:26:22,198+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:26:25,922+0200 INFO  (periodic/7090) [vdsm.api] START
repoStats(options=None) from=internal, task_id=59c658bf-3f91-4c87-8942-549703fcfbfb
(api:46)
2018-06-28 12:26:25,923+0200 INFO  (periodic/7090) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000306354', 'lastCheck': '5.4', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000571317', 'lastCheck': '1.9', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000244739', 'lastCheck': '2.1', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000327441', 'lastCheck': '1.7', 'valid': True}}
from=internal, task_id=59c658bf-3f91-4c87-8942-549703fcfbfb (api:52)
2018-06-28 12:26:29,874+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:26:29,875+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 40 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:26:32,636+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:26:32,662+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:26:34,220+0200 INFO  (jsonrpc/3) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=b219c494-760f-43fa-9220-22602e7b3aef (api:46)
2018-06-28 12:26:34,220+0200 INFO  (jsonrpc/3) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.00027001', 'lastCheck': '3.7', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00069247', 'lastCheck': '0.2', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000463365', 'lastCheck': '0.4', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000327441', 'lastCheck': '3.5', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=b219c494-760f-43fa-9220-22602e7b3aef (api:52)
2018-06-28 12:26:34,244+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:26:37,252+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:26:38,944+0200 INFO  (periodic/7085) [vdsm.api] START
getVolumeSize(sdUUID=u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'714ca627-a9d2-4c2f-8e29-00165c3c0778',
volUUID=u'171a4bcc-6e6b-4201-a2d9-1c08296517b7', options=None) from=internal,
task_id=576397ad-8f47-45dd-bfaf-d5d50808c165 (api:46)
2018-06-28 12:26:38,944+0200 INFO  (periodic/7085) [vdsm.api] FINISH getVolumeSize
return={'truesize': '128849018880', 'apparentsize':
'128849018880'} from=internal, task_id=576397ad-8f47-45dd-bfaf-d5d50808c165
(api:52)
2018-06-28 12:26:38,945+0200 INFO  (periodic/7093) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'c2cfa750-22ce-4c1d-802e-1739c6926f78',
volUUID=u'934fcb45-444b-45ef-975f-7d63f228dcc4', options=None) from=internal,
task_id=18608522-878e-4cc1-aa84-6ebcb822d5fa (api:46)
2018-06-28 12:26:38,945+0200 INFO  (periodic/7093) [vdsm.api] FINISH getVolumeSize
return={'truesize': '19327352832', 'apparentsize':
'19327352832'} from=internal, task_id=18608522-878e-4cc1-aa84-6ebcb822d5fa
(api:52)
2018-06-28 12:26:38,946+0200 INFO  (periodic/7090) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'cfe6d612-40cc-4f1d-990e-ae6c52a4f70f',
volUUID=u'02af893d-647e-4906-8814-de4003506c96', options=None) from=internal,
task_id=e3bc7fe2-2ced-4ae4-b5e4-64a4153172b3 (api:46)
2018-06-28 12:26:38,946+0200 INFO  (periodic/7090) [vdsm.api] FINISH getVolumeSize
return={'truesize': '26843545600', 'apparentsize':
'26843545600'} from=internal, task_id=e3bc7fe2-2ced-4ae4-b5e4-64a4153172b3
(api:52)
2018-06-28 12:26:38,947+0200 INFO  (periodic/7090) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'1a7022e0-54b5-419a-a144-439c8526e1cd',
volUUID=u'f05a1e54-e612-41d2-a7cc-d4f7e16dfc4f', options=None) from=internal,
task_id=8c9230ca-7c43-4c89-a799-1c98ebf74bab (api:46)
2018-06-28 12:26:38,947+0200 INFO  (periodic/7090) [vdsm.api] FINISH getVolumeSize
return={'truesize': '10737418240', 'apparentsize':
'10737418240'} from=internal, task_id=8c9230ca-7c43-4c89-a799-1c98ebf74bab
(api:52)
2018-06-28 12:26:38,947+0200 INFO  (periodic/7090) [vdsm.api] START
getVolumeSize(sdUUID=u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'cb2d4f33-6fa6-4448-b1cc-c060297407b7',
volUUID=u'e6168731-26fc-4dd2-92c1-443de74d49bb', options=None) from=internal,
task_id=4b7ec2e7-79a4-425d-a295-5918126a33cf (api:46)
2018-06-28 12:26:38,948+0200 INFO  (periodic/7090) [vdsm.api] FINISH getVolumeSize
return={'truesize': '1099511627776', 'apparentsize':
'1099511627776'} from=internal, task_id=4b7ec2e7-79a4-425d-a295-5918126a33cf
(api:52)
2018-06-28 12:26:38,949+0200 INFO  (periodic/7085) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'5fc7b643-db9a-4162-a67d-fb61a8cd87f7',
volUUID=u'd259d325-e2bc-4a2a-935b-6eca167c6b51', options=None) from=internal,
task_id=1a011e63-21ab-4b35-bd47-79ff77634775 (api:46)
2018-06-28 12:26:38,949+0200 INFO  (periodic/7085) [vdsm.api] FINISH getVolumeSize
return={'truesize': '80530636800', 'apparentsize':
'80530636800'} from=internal, task_id=1a011e63-21ab-4b35-bd47-79ff77634775
(api:52)
2018-06-28 12:26:38,950+0200 INFO  (periodic/7093) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'33235bbf-0156-421e-9391-0749247b6ba6',
volUUID=u'0d2949b6-af0f-4de2-b29a-10dcb39ad857', options=None) from=internal,
task_id=0f9ec553-58ac-48b4-97da-e5e08a861a6b (api:46)
2018-06-28 12:26:38,950+0200 INFO  (periodic/7093) [vdsm.api] FINISH getVolumeSize
return={'truesize': '5368709120', 'apparentsize':
'5368709120'} from=internal, task_id=0f9ec553-58ac-48b4-97da-e5e08a861a6b
(api:52)
2018-06-28 12:26:38,951+0200 INFO  (periodic/7093) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'5149067a-b18c-41cf-a355-033317291148',
volUUID=u'f0afa250-6704-410c-b9be-60b99cb28ce9', options=None) from=internal,
task_id=ccfa4241-0799-4645-bbde-a3ccd866107d (api:46)
2018-06-28 12:26:38,951+0200 INFO  (periodic/7093) [vdsm.api] FINISH getVolumeSize
return={'truesize': '16106127360', 'apparentsize':
'16106127360'} from=internal, task_id=ccfa4241-0799-4645-bbde-a3ccd866107d
(api:52)
2018-06-28 12:26:38,952+0200 INFO  (periodic/7090) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'07c38269-db89-4f7e-9194-f0c8923ed879',
volUUID=u'366d9d18-07fa-4342-9246-fc0f396e3059', options=None) from=internal,
task_id=061ca7ab-d0fd-406b-989f-c9cd0246d80c (api:46)
2018-06-28 12:26:38,952+0200 INFO  (periodic/7090) [vdsm.api] FINISH getVolumeSize
return={'truesize': '25769803776', 'apparentsize':
'25769803776'} from=internal, task_id=061ca7ab-d0fd-406b-989f-c9cd0246d80c
(api:52)
2018-06-28 12:26:38,953+0200 INFO  (periodic/7085) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'9d92c039-5c22-4459-bc8b-ca62f0d763dd',
volUUID=u'b9abe859-bd8f-412d-b1ca-f814f17d2572', options=None) from=internal,
task_id=c3aa0fd8-cfd6-47cc-8a4a-a799f2ccf232 (api:46)
2018-06-28 12:26:38,953+0200 INFO  (periodic/7085) [vdsm.api] FINISH getVolumeSize
return={'truesize': '144149839872', 'apparentsize':
'144149839872'} from=internal, task_id=c3aa0fd8-cfd6-47cc-8a4a-a799f2ccf232
(api:52)
2018-06-28 12:26:38,954+0200 INFO  (periodic/7085) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'a2f86027-9569-411a-8dec-b5ef0b6a30cd',
volUUID=u'1eb84b01-512a-4e08-b6bc-0c056c5c86b6', options=None) from=internal,
task_id=8ad4c399-0fe3-4236-859d-d18a02e4cafd (api:46)
2018-06-28 12:26:38,954+0200 INFO  (periodic/7085) [vdsm.api] FINISH getVolumeSize
return={'truesize': '72074919936', 'apparentsize':
'72074919936'} from=internal, task_id=8ad4c399-0fe3-4236-859d-d18a02e4cafd
(api:52)
2018-06-28 12:26:38,955+0200 INFO  (periodic/7091) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'1fe4d656-8f59-4221-a859-2f7bcbdb43c3',
volUUID=u'fbbd2aac-cb7a-471b-b95f-270ce6d00289', options=None) from=internal,
task_id=c5ecbbb8-503a-4e83-ac8e-9e1d63ac7347 (api:46)
2018-06-28 12:26:38,955+0200 INFO  (periodic/7091) [vdsm.api] FINISH getVolumeSize
return={'truesize': '53687091200', 'apparentsize':
'53687091200'} from=internal, task_id=c5ecbbb8-503a-4e83-ac8e-9e1d63ac7347
(api:52)
2018-06-28 12:26:39,877+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:26:39,877+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 50 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:26:40,962+0200 INFO  (periodic/7085) [vdsm.api] START
repoStats(options=None) from=internal, task_id=52703fc2-7917-4f58-a390-425850ca3b24
(api:46)
2018-06-28 12:26:40,962+0200 INFO  (periodic/7085) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000235121', 'lastCheck': '0.4', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00069247', 'lastCheck': '7.0', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000463365', 'lastCheck': '7.1', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000375592', 'lastCheck': '0.2', 'valid': True}}
from=internal, task_id=52703fc2-7917-4f58-a390-425850ca3b24 (api:52)
2018-06-28 12:26:47,671+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:26:47,697+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:26:49,242+0200 INFO  (jsonrpc/7) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=7409865e-ff52-406b-b22d-f2934674de2e (api:46)
2018-06-28 12:26:49,242+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000235121', 'lastCheck': '2.4', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000510816', 'lastCheck': '5.2', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000324262', 'lastCheck': '5.4', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000441143', 'lastCheck': '5.0', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=7409865e-ff52-406b-b22d-f2934674de2e (api:52)
2018-06-28 12:26:49,265+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.03 seconds (__init__:539)
2018-06-28 12:26:49,881+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:26:49,881+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 60 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:26:52,319+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:26:56,008+0200 INFO  (periodic/7093) [vdsm.api] START
repoStats(options=None) from=internal, task_id=dbbb6f8a-457c-4a6a-b1ec-3abd59962551
(api:46)
2018-06-28 12:26:56,009+0200 INFO  (periodic/7093) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000316826', 'lastCheck': '5.5', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000514374', 'lastCheck': '2.0', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000374509', 'lastCheck': '2.2', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000400921', 'lastCheck': '1.8', 'valid': True}}
from=internal, task_id=dbbb6f8a-457c-4a6a-b1ec-3abd59962551 (api:52)
2018-06-28 12:26:59,883+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:26:59,884+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 70 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:27:02,705+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:27:02,714+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:27:04,297+0200 INFO  (jsonrpc/3) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=4e03d286-f133-4767-8815-70f0fcdb8d44 (api:46)
2018-06-28 12:27:04,297+0200 INFO  (jsonrpc/3) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000339338', 'lastCheck': '3.8', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000629102', 'lastCheck': '0.3', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000554273', 'lastCheck': '0.5', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000380205', 'lastCheck': '0.1', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=4e03d286-f133-4767-8815-70f0fcdb8d44 (api:52)
2018-06-28 12:27:04,315+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:27:07,372+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:27:09,886+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:27:09,886+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 80 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:27:11,056+0200 INFO  (periodic/7090) [vdsm.api] START
repoStats(options=None) from=internal, task_id=0b893099-f458-458a-86cb-185409463a4c
(api:46)
2018-06-28 12:27:11,056+0200 INFO  (periodic/7090) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000252952', 'lastCheck': '0.5', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000629102', 'lastCheck': '7.1', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000554273', 'lastCheck': '7.3', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000380205', 'lastCheck': '0.3', 'valid': True}}
from=internal, task_id=0b893099-f458-458a-86cb-185409463a4c (api:52)
2018-06-28 12:27:16,838+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351449 (__init__:598)
2018-06-28 12:27:16,838+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351446 (__init__:598)
2018-06-28 12:27:16,838+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351445 (__init__:598)
2018-06-28 12:27:16,839+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351454 (__init__:598)
2018-06-28 12:27:16,839+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351451 (__init__:598)
2018-06-28 12:27:16,839+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351455 (__init__:598)
2018-06-28 12:27:16,839+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351453 (__init__:598)
2018-06-28 12:27:16,839+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351450 (__init__:598)
2018-06-28 12:27:16,840+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351447 (__init__:598)
2018-06-28 12:27:16,840+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351452 (__init__:598)
2018-06-28 12:27:16,840+0200 INFO  (monitor/48055e2) [IOProcessClient] Closing client
ioprocess-351448 (__init__:598)
2018-06-28 12:27:17,728+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:27:17,737+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:27:19,321+0200 INFO  (jsonrpc/7) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=5d54f7d8-0ebe-4175-b7b7-6b33cac964ad (api:46)
2018-06-28 12:27:19,321+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000252952', 'lastCheck': '2.5', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000510061', 'lastCheck': '5.3', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000301065', 'lastCheck': '5.5', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000442633', 'lastCheck': '5.1', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=5d54f7d8-0ebe-4175-b7b7-6b33cac964ad (api:52)
2018-06-28 12:27:19,341+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:27:19,888+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:27:19,888+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 90 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:27:22,422+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:27:26,094+0200 INFO  (periodic/7091) [vdsm.api] START
repoStats(options=None) from=internal, task_id=97f4298f-dae2-4107-9f7a-e62b99e3c6d5
(api:46)
2018-06-28 12:27:26,094+0200 INFO  (periodic/7091) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000345748', 'lastCheck': '5.6', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00064893', 'lastCheck': '2.1', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000473681', 'lastCheck': '2.3', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000367846', 'lastCheck': '1.9', 'valid': True}}
from=internal, task_id=97f4298f-dae2-4107-9f7a-e62b99e3c6d5 (api:52)
2018-06-28 12:27:29,891+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:27:29,892+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 100 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:27:32,745+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:27:32,772+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:27:34,354+0200 INFO  (jsonrpc/3) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=2ffd5e90-01c0-46fa-bc86-74e2a0c9bdb5 (api:46)
2018-06-28 12:27:34,355+0200 INFO  (jsonrpc/3) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000366741', 'lastCheck': '3.8', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00067226', 'lastCheck': '0.4', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.00046561', 'lastCheck': '0.6', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000365602', 'lastCheck': '0.1', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=2ffd5e90-01c0-46fa-bc86-74e2a0c9bdb5 (api:52)
2018-06-28 12:27:34,373+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:27:37,477+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:27:38,935+0200 INFO  (periodic/7085) [vdsm.api] START
getVolumeSize(sdUUID=u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'714ca627-a9d2-4c2f-8e29-00165c3c0778',
volUUID=u'171a4bcc-6e6b-4201-a2d9-1c08296517b7', options=None) from=internal,
task_id=28d944b0-ea96-4a56-afc1-4ca642804765 (api:46)
2018-06-28 12:27:38,936+0200 INFO  (periodic/7085) [vdsm.api] FINISH getVolumeSize
return={'truesize': '128849018880', 'apparentsize':
'128849018880'} from=internal, task_id=28d944b0-ea96-4a56-afc1-4ca642804765
(api:52)
2018-06-28 12:27:38,937+0200 INFO  (periodic/7090) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'c2cfa750-22ce-4c1d-802e-1739c6926f78',
volUUID=u'934fcb45-444b-45ef-975f-7d63f228dcc4', options=None) from=internal,
task_id=83d16ca0-5975-4e0f-84fe-1d63ed13783f (api:46)
2018-06-28 12:27:38,937+0200 INFO  (periodic/7090) [vdsm.api] FINISH getVolumeSize
return={'truesize': '19327352832', 'apparentsize':
'19327352832'} from=internal, task_id=83d16ca0-5975-4e0f-84fe-1d63ed13783f
(api:52)
2018-06-28 12:27:38,938+0200 INFO  (periodic/7091) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'cfe6d612-40cc-4f1d-990e-ae6c52a4f70f',
volUUID=u'02af893d-647e-4906-8814-de4003506c96', options=None) from=internal,
task_id=161ed3bc-4d7d-4c9b-9915-f67829d7183d (api:46)
2018-06-28 12:27:38,938+0200 INFO  (periodic/7091) [vdsm.api] FINISH getVolumeSize
return={'truesize': '26843545600', 'apparentsize':
'26843545600'} from=internal, task_id=161ed3bc-4d7d-4c9b-9915-f67829d7183d
(api:52)
2018-06-28 12:27:38,939+0200 INFO  (periodic/7091) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'1a7022e0-54b5-419a-a144-439c8526e1cd',
volUUID=u'f05a1e54-e612-41d2-a7cc-d4f7e16dfc4f', options=None) from=internal,
task_id=e4fd4063-be84-493f-8616-1a23ca7085b3 (api:46)
2018-06-28 12:27:38,939+0200 INFO  (periodic/7091) [vdsm.api] FINISH getVolumeSize
return={'truesize': '10737418240', 'apparentsize':
'10737418240'} from=internal, task_id=e4fd4063-be84-493f-8616-1a23ca7085b3
(api:52)
2018-06-28 12:27:38,939+0200 INFO  (periodic/7091) [vdsm.api] START
getVolumeSize(sdUUID=u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'cb2d4f33-6fa6-4448-b1cc-c060297407b7',
volUUID=u'e6168731-26fc-4dd2-92c1-443de74d49bb', options=None) from=internal,
task_id=6ada779f-ea02-48f2-99ea-e7090a7e4b18 (api:46)
2018-06-28 12:27:38,940+0200 INFO  (periodic/7091) [vdsm.api] FINISH getVolumeSize
return={'truesize': '1099511627776', 'apparentsize':
'1099511627776'} from=internal, task_id=6ada779f-ea02-48f2-99ea-e7090a7e4b18
(api:52)
2018-06-28 12:27:38,940+0200 INFO  (periodic/7085) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'5fc7b643-db9a-4162-a67d-fb61a8cd87f7',
volUUID=u'd259d325-e2bc-4a2a-935b-6eca167c6b51', options=None) from=internal,
task_id=89408443-0882-42f5-9c61-4699fdab4556 (api:46)
2018-06-28 12:27:38,941+0200 INFO  (periodic/7085) [vdsm.api] FINISH getVolumeSize
return={'truesize': '80530636800', 'apparentsize':
'80530636800'} from=internal, task_id=89408443-0882-42f5-9c61-4699fdab4556
(api:52)
2018-06-28 12:27:38,941+0200 INFO  (periodic/7090) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'33235bbf-0156-421e-9391-0749247b6ba6',
volUUID=u'0d2949b6-af0f-4de2-b29a-10dcb39ad857', options=None) from=internal,
task_id=e440afe9-a3fb-4942-9e68-3e14f5a9d271 (api:46)
2018-06-28 12:27:38,942+0200 INFO  (periodic/7090) [vdsm.api] FINISH getVolumeSize
return={'truesize': '5368709120', 'apparentsize':
'5368709120'} from=internal, task_id=e440afe9-a3fb-4942-9e68-3e14f5a9d271
(api:52)
2018-06-28 12:27:38,942+0200 INFO  (periodic/7090) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'5149067a-b18c-41cf-a355-033317291148',
volUUID=u'f0afa250-6704-410c-b9be-60b99cb28ce9', options=None) from=internal,
task_id=3399f449-2dcc-4d82-8285-f1945d0e2baf (api:46)
2018-06-28 12:27:38,942+0200 INFO  (periodic/7090) [vdsm.api] FINISH getVolumeSize
return={'truesize': '16106127360', 'apparentsize':
'16106127360'} from=internal, task_id=3399f449-2dcc-4d82-8285-f1945d0e2baf
(api:52)
2018-06-28 12:27:38,943+0200 INFO  (periodic/7091) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'07c38269-db89-4f7e-9194-f0c8923ed879',
volUUID=u'366d9d18-07fa-4342-9246-fc0f396e3059', options=None) from=internal,
task_id=1d361a42-8c9e-4885-a8ff-e7ce0c1c224f (api:46)
2018-06-28 12:27:38,943+0200 INFO  (periodic/7091) [vdsm.api] FINISH getVolumeSize
return={'truesize': '25769803776', 'apparentsize':
'25769803776'} from=internal, task_id=1d361a42-8c9e-4885-a8ff-e7ce0c1c224f
(api:52)
2018-06-28 12:27:38,944+0200 INFO  (periodic/7085) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'9d92c039-5c22-4459-bc8b-ca62f0d763dd',
volUUID=u'b9abe859-bd8f-412d-b1ca-f814f17d2572', options=None) from=internal,
task_id=a17d38fc-772e-47ad-99e1-fd7fea5e2b97 (api:46)
2018-06-28 12:27:38,944+0200 INFO  (periodic/7085) [vdsm.api] FINISH getVolumeSize
return={'truesize': '144149839872', 'apparentsize':
'144149839872'} from=internal, task_id=a17d38fc-772e-47ad-99e1-fd7fea5e2b97
(api:52)
2018-06-28 12:27:38,945+0200 INFO  (periodic/7085) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'a2f86027-9569-411a-8dec-b5ef0b6a30cd',
volUUID=u'1eb84b01-512a-4e08-b6bc-0c056c5c86b6', options=None) from=internal,
task_id=aacf55d3-3fdd-49e1-af58-bae7ce9fbd6f (api:46)
2018-06-28 12:27:38,945+0200 INFO  (periodic/7085) [vdsm.api] FINISH getVolumeSize
return={'truesize': '72074919936', 'apparentsize':
'72074919936'} from=internal, task_id=aacf55d3-3fdd-49e1-af58-bae7ce9fbd6f
(api:52)
2018-06-28 12:27:38,945+0200 INFO  (periodic/7093) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'1fe4d656-8f59-4221-a859-2f7bcbdb43c3',
volUUID=u'fbbd2aac-cb7a-471b-b95f-270ce6d00289', options=None) from=internal,
task_id=6213f532-b194-467b-9799-02032e59af58 (api:46)
2018-06-28 12:27:38,946+0200 INFO  (periodic/7093) [vdsm.api] FINISH getVolumeSize
return={'truesize': '53687091200', 'apparentsize':
'53687091200'} from=internal, task_id=6213f532-b194-467b-9799-02032e59af58
(api:52)
2018-06-28 12:27:39,894+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:27:39,894+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 110 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:27:41,143+0200 INFO  (periodic/7085) [vdsm.api] START
repoStats(options=None) from=internal, task_id=79f2e7e6-ef1d-47d8-87a9-46aefcd02467
(api:46)
2018-06-28 12:27:41,143+0200 INFO  (periodic/7085) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000291026', 'lastCheck': '0.6', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00067226', 'lastCheck': '7.1', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.00046561', 'lastCheck': '7.3', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000365602', 'lastCheck': '0.4', 'valid': True}}
from=internal, task_id=79f2e7e6-ef1d-47d8-87a9-46aefcd02467 (api:52)
2018-06-28 12:27:41,313+0200 INFO  (monitor/68b8aaf) [storage.LVM] Refreshing lvs:
vg=68b8aaff-770d-4a08-800b-0c15e94efaa8 lvs=['metadata'] (lvm:1291)
2018-06-28 12:27:41,313+0200 INFO  (monitor/68b8aaf) [storage.LVM] Refreshing LVs
(vg=68b8aaff-770d-4a08-800b-0c15e94efaa8, lvs=['metadata']) (lvm:1319)
2018-06-28 12:27:41,475+0200 INFO  (monitor/68b8aaf) [storage.LVM] Refreshing lvs:
vg=68b8aaff-770d-4a08-800b-0c15e94efaa8 lvs=['ids'] (lvm:1291)
2018-06-28 12:27:41,476+0200 INFO  (monitor/68b8aaf) [storage.LVM] Refreshing LVs
(vg=68b8aaff-770d-4a08-800b-0c15e94efaa8, lvs=['ids']) (lvm:1319)
2018-06-28 12:27:41,544+0200 INFO  (monitor/68b8aaf) [storage.LVM] Refreshing lvs:
vg=68b8aaff-770d-4a08-800b-0c15e94efaa8 lvs=['leases'] (lvm:1291)
2018-06-28 12:27:41,544+0200 INFO  (monitor/68b8aaf) [storage.LVM] Refreshing LVs
(vg=68b8aaff-770d-4a08-800b-0c15e94efaa8, lvs=['leases']) (lvm:1319)
2018-06-28 12:27:41,622+0200 INFO  (monitor/68b8aaf) [storage.LVM] Refreshing lvs:
vg=68b8aaff-770d-4a08-800b-0c15e94efaa8 lvs=['metadata', 'leases',
'ids', 'inbox', 'outbox', 'xleases', 'master']
(lvm:1291)
2018-06-28 12:27:41,623+0200 INFO  (monitor/68b8aaf) [storage.LVM] Refreshing LVs
(vg=68b8aaff-770d-4a08-800b-0c15e94efaa8, lvs=['metadata', 'leases',
'ids', 'inbox', 'outbox', 'xleases', 'master'])
(lvm:1319)
2018-06-28 12:27:41,716+0200 INFO  (monitor/68b8aaf) [storage.StorageDomain] Resource
namespace 01_img_68b8aaff-770d-4a08-800b-0c15e94efaa8 already registered (sd:758)
2018-06-28 12:27:41,716+0200 INFO  (monitor/68b8aaf) [storage.StorageDomain] Resource
namespace 02_vol_68b8aaff-770d-4a08-800b-0c15e94efaa8 already registered (sd:767)
2018-06-28 12:27:41,716+0200 INFO  (monitor/68b8aaf) [storage.StorageDomain] Resource
namespace 03_lvm_68b8aaff-770d-4a08-800b-0c15e94efaa8 already registered (blockSD:989)
2018-06-28 12:27:47,784+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:27:47,809+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:27:49,415+0200 INFO  (jsonrpc/7) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=01be8d64-d54a-4c9d-979e-3971279eac9b (api:46)
2018-06-28 12:27:49,416+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000291026', 'lastCheck': '2.6', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000573367', 'lastCheck': '5.4', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000457603', 'lastCheck': '5.6', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000393837', 'lastCheck': '5.2', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=01be8d64-d54a-4c9d-979e-3971279eac9b (api:52)
2018-06-28 12:27:49,435+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:27:49,896+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:27:49,897+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 120 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:27:52,532+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:27:56,181+0200 INFO  (periodic/7093) [vdsm.api] START
repoStats(options=None) from=internal, task_id=db929a1d-f13a-4ea3-89fb-4d8825204cac
(api:46)
2018-06-28 12:27:56,182+0200 INFO  (periodic/7093) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000398606', 'lastCheck': '5.7', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000667386', 'lastCheck': '2.2', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000471581', 'lastCheck': '2.3', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000276833', 'lastCheck': '2.0', 'valid': True}}
from=internal, task_id=db929a1d-f13a-4ea3-89fb-4d8825204cac (api:52)
2018-06-28 12:27:59,899+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration stalling: remaining
(2112MiB) > lowmark (2112MiB). Refer to RHBZ#919201. (migration:785)
2018-06-28 12:27:59,899+0200 INFO  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Migration Progress: 130 seconds
elapsed, 1% of data processed, total data: 2113MB, processed data: 0MB, remaining data:
2112MB, transfer speed 0MBps, zero pages: 6MB, compressed: 0MB, dirty rate: 0, memory
iteration: 1 (migration:815)
2018-06-28 12:28:00,752+0200 INFO  (monitor/8924ce2) [storage.LVM] Refreshing lvs:
vg=8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5 lvs=['metadata'] (lvm:1291)
2018-06-28 12:28:00,752+0200 INFO  (monitor/8924ce2) [storage.LVM] Refreshing LVs
(vg=8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5, lvs=['metadata']) (lvm:1319)
2018-06-28 12:28:00,895+0200 INFO  (monitor/8924ce2) [storage.LVM] Refreshing lvs:
vg=8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5 lvs=['ids'] (lvm:1291)
2018-06-28 12:28:00,896+0200 INFO  (monitor/8924ce2) [storage.LVM] Refreshing LVs
(vg=8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5, lvs=['ids']) (lvm:1319)
2018-06-28 12:28:00,962+0200 INFO  (monitor/8924ce2) [storage.LVM] Refreshing lvs:
vg=8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5 lvs=['leases'] (lvm:1291)
2018-06-28 12:28:00,963+0200 INFO  (monitor/8924ce2) [storage.LVM] Refreshing LVs
(vg=8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5, lvs=['leases']) (lvm:1319)
2018-06-28 12:28:01,033+0200 INFO  (monitor/8924ce2) [storage.LVM] Refreshing lvs:
vg=8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5 lvs=['metadata', 'leases',
'ids', 'inbox', 'outbox', 'xleases', 'master']
(lvm:1291)
2018-06-28 12:28:01,033+0200 INFO  (monitor/8924ce2) [storage.LVM] Refreshing LVs
(vg=8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5, lvs=['metadata', 'leases',
'ids', 'inbox', 'outbox', 'xleases', 'master'])
(lvm:1319)
2018-06-28 12:28:01,113+0200 INFO  (monitor/8924ce2) [storage.StorageDomain] Resource
namespace 01_img_8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5 already registered (sd:758)
2018-06-28 12:28:01,114+0200 INFO  (monitor/8924ce2) [storage.StorageDomain] Resource
namespace 02_vol_8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5 already registered (sd:767)
2018-06-28 12:28:01,114+0200 INFO  (monitor/8924ce2) [storage.StorageDomain] Resource
namespace 03_lvm_8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5 already registered (blockSD:989)
2018-06-28 12:28:02,822+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:28:02,848+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:28:04,455+0200 INFO  (jsonrpc/3) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,53170, task_id=8d2d2379-1f5a-47a1-8b37-b922d13a02c6 (api:46)
2018-06-28 12:28:04,456+0200 INFO  (jsonrpc/3) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000321492', 'lastCheck': '3.9', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000650208', 'lastCheck': '0.5', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000296691', 'lastCheck': '0.7', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000362554', 'lastCheck': '0.2', 'valid': True}}
from=::ffff:10.157.8.36,53170, task_id=8d2d2379-1f5a-47a1-8b37-b922d13a02c6 (api:52)
2018-06-28 12:28:04,473+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:28:07,585+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:28:09,902+0200 WARN  (migmon/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') The migration took 140 seconds which
is exceeding the configured maximum time for migrations of 131 seconds. The migration will
be aborted. (migration:773)
2018-06-28 12:28:10,955+0200 ERROR (migsrc/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Operation abgebrochen:
Migrations-Job: abgebrochen durch Client (migration:287)
2018-06-28 12:28:11,174+0200 ERROR (migsrc/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Failed to migrate (migration:429)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/virt/migration.py", line 411, in
run
    self._startUnderlyingMigration(time.time())
  File "/usr/lib/python2.7/site-packages/vdsm/virt/migration.py", line 489, in
_startUnderlyingMigration
    self._perform_with_downtime_thread(duri, muri)
  File "/usr/lib/python2.7/site-packages/vdsm/virt/migration.py", line 556, in
_perform_with_downtime_thread
    self._perform_migration(duri, muri)
  File "/usr/lib/python2.7/site-packages/vdsm/virt/migration.py", line 529, in
_perform_migration
    self._vm._dom.migrateToURI3(duri, params, flags)
  File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line 69, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", line 123,
in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/utils.py", line 1006, in wrapper
    return func(inst, *args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 1679, in
migrateToURI3
    if ret == -1: raise libvirtError ('virDomainMigrateToURI3() failed',
dom=self)
libvirtError: Operation abgebrochen: Migrations-Job: abgebrochen durch Client
2

and vdsm.log from destination:
2018-06-28 12:25:01,919+0200 INFO  (periodic/6162) [vdsm.api] START
repoStats(options=None) from=internal, task_id=cb3869db-d960-49e0-ba4a-d726bf27539b
(api:46)
2018-06-28 12:25:01,920+0200 INFO  (periodic/6162) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000606644', 'lastCheck': '0.5', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000570293', 'lastCheck': '3.6', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000286344', 'lastCheck': '3.7', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000345685', 'lastCheck': '1.6', 'valid': True}}
from=internal, task_id=cb3869db-d960-49e0-ba4a-d726bf27539b (api:52)
2018-06-28 12:25:04,109+0200 INFO  (jsonrpc/0) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,36662, task_id=dc938a7a-3c7a-40d3-9e06-7f712e7fc527 (api:46)
2018-06-28 12:25:04,110+0200 INFO  (jsonrpc/0) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000606644', 'lastCheck': '2.7', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000570293', 'lastCheck': '5.8', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000286344', 'lastCheck': '5.9', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000345685', 'lastCheck': '3.7', 'valid': True}}
from=::ffff:10.157.8.36,36662, task_id=dc938a7a-3c7a-40d3-9e06-7f712e7fc527 (api:52)
2018-06-28 12:25:04,157+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.05 seconds (__init__:539)
2018-06-28 12:25:12,757+0200 INFO  (jsonrpc/4) [vdsm.api] START
setBalloonTarget(target=9874629) from=::1,46990 (api:46)
2018-06-28 12:25:12,774+0200 INFO  (jsonrpc/4) [vdsm.api] FINISH setBalloonTarget
return={'status': {'message': 'Done', 'code': 0}}
from=::1,46990 (api:52)
2018-06-28 12:25:12,774+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
VM.setBalloonTarget succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:25:13,453+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:25:14,824+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:25:14,847+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:25:17,007+0200 INFO  (periodic/6163) [vdsm.api] START
repoStats(options=None) from=internal, task_id=3136344f-2e0d-4d0d-83a7-b6cd8809acbc
(api:46)
2018-06-28 12:25:17,008+0200 INFO  (periodic/6163) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000507353', 'lastCheck': '1.2', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000568841', 'lastCheck': '1.2', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000262659', 'lastCheck': '8.8', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000300632', 'lastCheck': '6.6', 'valid': True}}
from=internal, task_id=3136344f-2e0d-4d0d-83a7-b6cd8809acbc (api:52)
2018-06-28 12:25:19,137+0200 INFO  (jsonrpc/6) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,36662, task_id=8c36bf93-c4b6-49a6-a019-82c02b98e03f (api:46)
2018-06-28 12:25:19,138+0200 INFO  (jsonrpc/6) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000507353', 'lastCheck': '3.4', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000588412', 'lastCheck': '0.8', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000514061', 'lastCheck': '1.0', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000388286', 'lastCheck': '0.5', 'valid': True}}
from=::ffff:10.157.8.36,36662, task_id=8c36bf93-c4b6-49a6-a019-82c02b98e03f (api:52)
2018-06-28 12:25:19,187+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.05 seconds (__init__:539)
2018-06-28 12:25:27,960+0200 INFO  (jsonrpc/1) [vdsm.api] START
setBalloonTarget(target=9854363) from=::1,46990 (api:46)
2018-06-28 12:25:27,993+0200 INFO  (jsonrpc/1) [vdsm.api] FINISH setBalloonTarget
return={'status': {'message': 'Done', 'code': 0}}
from=::1,46990 (api:52)
2018-06-28 12:25:27,994+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call
VM.setBalloonTarget succeeded in 0.03 seconds (__init__:539)
2018-06-28 12:25:28,530+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:25:29,870+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:25:29,914+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:25:32,113+0200 INFO  (periodic/6162) [vdsm.api] START
repoStats(options=None) from=internal, task_id=5c30fd65-66e8-4f36-b036-47bec09fd522
(api:46)
2018-06-28 12:25:32,114+0200 INFO  (periodic/6162) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000500395', 'lastCheck': '0.7', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000620907', 'lastCheck': '3.8', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000339191', 'lastCheck': '3.9', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000404014', 'lastCheck': '1.7', 'valid': True}}
from=internal, task_id=5c30fd65-66e8-4f36-b036-47bec09fd522 (api:52)
2018-06-28 12:25:34,151+0200 INFO  (jsonrpc/5) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,36662, task_id=9351125d-3a9e-4e22-9bdb-e86ed35032fd (api:46)
2018-06-28 12:25:34,151+0200 INFO  (jsonrpc/5) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000500395', 'lastCheck': '2.8', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000620907', 'lastCheck': '5.9', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000339191', 'lastCheck': '6.0', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000404014', 'lastCheck': '3.8', 'valid': True}}
from=::ffff:10.157.8.36,36662, task_id=9351125d-3a9e-4e22-9bdb-e86ed35032fd (api:52)
2018-06-28 12:25:34,198+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.05 seconds (__init__:539)
2018-06-28 12:25:41,239+0200 INFO  (periodic/6164) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'6c94e2de-d65d-45f3-842e-68c006bc1a15',
volUUID=u'70e61b28-fb15-4c0f-a425-bcbf8a506423', options=None) from=internal,
task_id=d17b01b6-2321-49c9-a564-1689dacbae66 (api:46)
2018-06-28 12:25:41,240+0200 INFO  (periodic/6164) [vdsm.api] FINISH getVolumeSize
return={'truesize': '6442450944', 'apparentsize':
'6442450944'} from=internal, task_id=d17b01b6-2321-49c9-a564-1689dacbae66
(api:52)
2018-06-28 12:25:41,241+0200 INFO  (periodic/6164) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'30e80e8a-a30d-4f4a-b593-d5df59acd6b9',
volUUID=u'dc6b8058-895d-48c3-aff8-d381877a9904', options=None) from=internal,
task_id=ca550e56-5d6c-4f71-aa82-f572feb23192 (api:46)
2018-06-28 12:25:41,241+0200 INFO  (periodic/6164) [vdsm.api] FINISH getVolumeSize
return={'truesize': '80530636800', 'apparentsize':
'80530636800'} from=internal, task_id=ca550e56-5d6c-4f71-aa82-f572feb23192
(api:52)
2018-06-28 12:25:41,242+0200 INFO  (periodic/6164) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'55a7014f-aaaa-4a48-8522-8d962fa3e37a',
volUUID=u'd0a9a441-6c77-4539-8851-908e3d91331c', options=None) from=internal,
task_id=633bf144-d519-42fc-949a-c3edab728255 (api:46)
2018-06-28 12:25:41,242+0200 INFO  (periodic/6164) [vdsm.api] FINISH getVolumeSize
return={'truesize': '80530636800', 'apparentsize':
'80530636800'} from=internal, task_id=633bf144-d519-42fc-949a-c3edab728255
(api:52)
2018-06-28 12:25:41,243+0200 INFO  (periodic/6164) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'0e3981b3-045b-4a66-a08e-b0bfccd81f5a',
volUUID=u'acf2c734-b052-445b-98cc-e7f3eca8bd76', options=None) from=internal,
task_id=8486f1b4-a8a8-4692-97ae-ea1c7f135758 (api:46)
2018-06-28 12:25:41,243+0200 INFO  (periodic/6164) [vdsm.api] FINISH getVolumeSize
return={'truesize': '80530636800', 'apparentsize':
'80530636800'} from=internal, task_id=8486f1b4-a8a8-4692-97ae-ea1c7f135758
(api:52)
2018-06-28 12:25:41,244+0200 INFO  (periodic/6160) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'df435578-a524-4cd8-9b3d-74f36c4b182f',
volUUID=u'd971520b-464b-4939-bff8-562572e9a439', options=None) from=internal,
task_id=bc538510-62f6-4eba-bcb6-bbd1088b3673 (api:46)
2018-06-28 12:25:41,244+0200 INFO  (periodic/6160) [vdsm.api] FINISH getVolumeSize
return={'truesize': '67645734912', 'apparentsize':
'67645734912'} from=internal, task_id=bc538510-62f6-4eba-bcb6-bbd1088b3673
(api:52)
2018-06-28 12:25:41,245+0200 INFO  (periodic/6160) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'b5ee85a6-eaef-4cc4-9506-8ccd540a03fb',
volUUID=u'd9853bb2-54c3-44c7-be61-862484ed031d', options=None) from=internal,
task_id=83653b45-6b15-485f-9c7a-65df75e1af8a (api:46)
2018-06-28 12:25:41,245+0200 INFO  (periodic/6160) [vdsm.api] FINISH getVolumeSize
return={'truesize': '215822106624', 'apparentsize':
'215822106624'} from=internal, task_id=83653b45-6b15-485f-9c7a-65df75e1af8a
(api:52)
2018-06-28 12:25:41,246+0200 INFO  (periodic/6162) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'6f19ce7b-78d4-4c04-a9e7-97cf2667fbc1',
volUUID=u'465e9ac1-08ee-48ec-9159-7dde0ae00499', options=None) from=internal,
task_id=d761d21f-6513-4507-b22a-ec1ba4ad2c98 (api:46)
2018-06-28 12:25:41,247+0200 INFO  (periodic/6162) [vdsm.api] FINISH getVolumeSize
return={'truesize': '17179869184', 'apparentsize':
'17179869184'} from=internal, task_id=d761d21f-6513-4507-b22a-ec1ba4ad2c98
(api:52)
2018-06-28 12:25:41,248+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'157e6919-01d1-47d6-b2e9-4934a5e2743b',
volUUID=u'bbe845e7-5b64-4a78-8c9c-c078d23ea50e', options=None) from=internal,
task_id=5fffe581-8293-492b-87ac-6b2ac99617b6 (api:46)
2018-06-28 12:25:41,248+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '21474836480', 'apparentsize':
'21474836480'} from=internal, task_id=5fffe581-8293-492b-87ac-6b2ac99617b6
(api:52)
2018-06-28 12:25:41,249+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'3ec22ced-a137-4c4c-8fdc-80afedde01d3',
volUUID=u'b8aeb887-cc52-4941-b91c-10673a772d60', options=None) from=internal,
task_id=6a76cbaa-6704-4c6d-80cb-84a8b7381f92 (api:46)
2018-06-28 12:25:41,249+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '10737418240', 'apparentsize':
'10737418240'} from=internal, task_id=6a76cbaa-6704-4c6d-80cb-84a8b7381f92
(api:52)
2018-06-28 12:25:41,250+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'b9b990e3-abcd-49e0-a4be-fa4f2e3ab17d',
volUUID=u'd4eb437e-4442-4469-a3b7-c33ce3ef0619', options=None) from=internal,
task_id=87adcf3e-0e0e-4a8e-8912-6985b06b6ee6 (api:46)
2018-06-28 12:25:41,250+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '44023414784', 'apparentsize':
'44023414784'} from=internal, task_id=87adcf3e-0e0e-4a8e-8912-6985b06b6ee6
(api:52)
2018-06-28 12:25:41,251+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'ac124e30-064b-4af2-a32b-dea3d9a492a9',
volUUID=u'fa387755-b06a-4fda-ad19-6761a765e257', options=None) from=internal,
task_id=183a7469-58d8-4cad-8c63-a24c00df50bc (api:46)
2018-06-28 12:25:41,251+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '47244640256', 'apparentsize':
'47244640256'} from=internal, task_id=183a7469-58d8-4cad-8c63-a24c00df50bc
(api:52)
2018-06-28 12:25:41,252+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'983a5eff-5a53-4677-9d9f-899e500f8535',
volUUID=u'5769e03a-2df4-4514-9b93-859fe453e6f9', options=None) from=internal,
task_id=b2d4c682-4ffd-46ab-bb2f-cf03edfb1325 (api:46)
2018-06-28 12:25:41,252+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '107374182400', 'apparentsize':
'107374182400'} from=internal, task_id=b2d4c682-4ffd-46ab-bb2f-cf03edfb1325
(api:52)
2018-06-28 12:25:41,253+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'53152751-8ae3-4760-aabf-e5f7b0ec6434',
volUUID=u'6ad3a22b-dc92-45f8-b06b-27d22ba79ad3', options=None) from=internal,
task_id=692228d9-624b-45f0-b0da-08fda6b434cc (api:46)
2018-06-28 12:25:41,253+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '21474836480', 'apparentsize':
'21474836480'} from=internal, task_id=692228d9-624b-45f0-b0da-08fda6b434cc
(api:52)
2018-06-28 12:25:41,254+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'28aa3761-33d2-4824-b3bb-55fd93996582',
volUUID=u'8b7c0a22-79de-4e36-9e8a-934aad6d4c7e', options=None) from=internal,
task_id=95868d0a-2efc-44a7-b688-da156122ad38 (api:46)
2018-06-28 12:25:41,254+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '10737418240', 'apparentsize':
'10737418240'} from=internal, task_id=95868d0a-2efc-44a7-b688-da156122ad38
(api:52)
2018-06-28 12:25:41,255+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'c9366f52-f1a8-411a-8e0c-3fcb0da264eb',
volUUID=u'841b22dd-0ba0-487f-9256-b2e481b4d92b', options=None) from=internal,
task_id=211d11fb-dfeb-45d8-93a2-17f0e4289cd0 (api:46)
2018-06-28 12:25:41,255+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '26843545600', 'apparentsize':
'26843545600'} from=internal, task_id=211d11fb-dfeb-45d8-93a2-17f0e4289cd0
(api:52)
2018-06-28 12:25:41,256+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'55d90f2e-05d0-4a17-b066-ef52d0f21469',
volUUID=u'cf7c3c97-1a7c-4b54-a21d-8d3232fb1667', options=None) from=internal,
task_id=e2b43a11-334e-4f30-a7de-b41ffe5ceb33 (api:46)
2018-06-28 12:25:41,257+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '32212254720', 'apparentsize':
'32212254720'} from=internal, task_id=e2b43a11-334e-4f30-a7de-b41ffe5ceb33
(api:52)
2018-06-28 12:25:41,257+0200 INFO  (periodic/6163) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'4910730a-1537-4564-80fe-5df0eb9ca276',
volUUID=u'77593d90-f216-492d-aced-264ba5c0632f', options=None) from=internal,
task_id=e28bdb33-9438-414e-9b58-f4f81c117c34 (api:46)
2018-06-28 12:25:41,258+0200 INFO  (periodic/6163) [vdsm.api] FINISH getVolumeSize
return={'truesize': '17716740096', 'apparentsize':
'17716740096'} from=internal, task_id=e28bdb33-9438-414e-9b58-f4f81c117c34
(api:52)
2018-06-28 12:25:43,195+0200 INFO  (jsonrpc/7) [vdsm.api] START
setBalloonTarget(target=9835175) from=::1,46990 (api:46)
2018-06-28 12:25:43,211+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH setBalloonTarget
return={'status': {'message': 'Done', 'code': 0}}
from=::1,46990 (api:52)
2018-06-28 12:25:43,212+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
VM.setBalloonTarget succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:25:43,595+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:25:44,923+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:25:44,945+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:25:47,193+0200 INFO  (periodic/6163) [vdsm.api] START
repoStats(options=None) from=internal, task_id=0676d13f-11b7-473d-8c58-157bec36772f
(api:46)
2018-06-28 12:25:47,193+0200 INFO  (periodic/6163) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000490941', 'lastCheck': '1.4', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.00065911', 'lastCheck': '1.4', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000546678', 'lastCheck': '9.0', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000449752', 'lastCheck': '6.8', 'valid': True}}
from=internal, task_id=0676d13f-11b7-473d-8c58-157bec36772f (api:52)
2018-06-28 12:25:48,932+0200 INFO  (Reactor thread) [ProtocolDetector.AcceptorImpl]
Accepted connection from ::ffff:10.157.8.40:35732 (protocoldetector:72)
2018-06-28 12:25:48,941+0200 INFO  (Reactor thread) [ProtocolDetector.Detector] Detected
protocol stomp from ::ffff:10.157.8.40:35732 (protocoldetector:127)
2018-06-28 12:25:48,942+0200 INFO  (Reactor thread) [Broker.StompAdapter] Processing
CONNECT request (stompreactor:103)
2018-06-28 12:25:48,943+0200 INFO  (JsonRpc (StompReactor)) [Broker.StompAdapter]
Subscribe command received (stompreactor:132)
2018-06-28 12:25:49,169+0200 INFO  (jsonrpc/2) [vdsm.api] START repoStats(options=None)
from=::ffff:10.157.8.36,36662, task_id=8c64d73b-10e4-45f7-8c49-43f5e6e61ee5 (api:46)
2018-06-28 12:25:49,170+0200 INFO  (jsonrpc/2) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000490941', 'lastCheck': '3.4', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000692455', 'lastCheck': '0.9', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000301581', 'lastCheck': '1.0', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000362669', 'lastCheck': '0.6', 'valid': True}}
from=::ffff:10.157.8.36,36662, task_id=8c64d73b-10e4-45f7-8c49-43f5e6e61ee5 (api:52)
2018-06-28 12:25:49,218+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call
Host.getStats succeeded in 0.05 seconds (__init__:539)
2018-06-28 12:25:49,233+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call Host.ping
succeeded in 0.00 seconds (__init__:539)
2018-06-28 12:25:49,276+0200 INFO  (jsonrpc/4) [vdsm.api] START
__init__(cif=<clientIF.clientIF object at 0x255ef10>, params={u'status':
u'Up', u'acpiEnable': u'true', u'emulatedMachine':
u'pc-i440fx-rhel7.3.0', u'afterMigrationStatus': u'',
u'enableGuestEvents': False, u'vmId':
u'a54af7cd-3b89-43c1-82b3-ae0c08d103d3', u'elapsedTimeOffset':
791575.6959090233, u'guestDiskMapping': {u'1fe4d656-8f59-4221-a':
{u'name': u'/dev/vda'}}, u'transparentHugePages': u'true',
u'timeOffset': u'0', u'cpuType': u'Westmere',
u'custom':
{u'device_3b6d92fa-999b-40cf-883e-209fa76b1751device_8b7ae8e2-ef0d-45bb-9a99-e33d1b9af920device_83fbbdab-d906-4629-9c6a-29fc59410630':
u"VmDevice:{id='VmDeviceId:{deviceId='83fbbdab-d906-4629-9c6a-29fc59410630',
vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3'}', device='unix',
type='CHANNEL', specParams='[]', address='{bus=0, controller=0,
type=virtio-serial, port=2}', managed='false', plugged='true',
readOnly='false', deviceAlias='channel1', customProperties='[]',
snapsho
 tId='null', logicalName='null', hostDevice='null'}",
u'device_3b6d92fa-999b-40cf-883e-209fa76b1751device_8b7ae8e2-ef0d-45bb-9a99-e33d1b9af920device_83fbbdab-d906-4629-9c6a-29fc59410630device_4bec2c2b-442c-4a7a-9759-a7a13729bc90':
u"VmDevice:{id='VmDeviceId:{deviceId='4bec2c2b-442c-4a7a-9759-a7a13729bc90',
vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3'}', device='tablet',
type='UNKNOWN', specParams='[]', address='{bus=0, type=usb,
port=1}', managed='false', plugged='true', readOnly='false',
deviceAlias='input0', customProperties='[]', snapshotId='null',
logicalName='null', hostDevice='null'}",
u'device_3b6d92fa-999b-40cf-883e-209fa76b1751':
u"VmDevice:{id='VmDeviceId:{deviceId='3b6d92fa-999b-40cf-883e-209fa76b1751',
vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3'}', device='ide',
type='CONTROLLER', specParams='[]', address='{slot=0x01, bus=0x00,
domain=0x0000, type=pci, function=0x1}', managed='false',
plugged='true', readOnly='false', deviceAlias='ide',
customProperties='[]', snapshotId='n
 ull', logicalName='null', hostDevice='null'}",
u'device_3b6d92fa-999b-40cf-883e-209fa76b1751device_8b7ae8e2-ef0d-45bb-9a99-e33d1b9af920':
u"VmDevice:{id='VmDeviceId:{deviceId='8b7ae8e2-ef0d-45bb-9a99-e33d1b9af920',
vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3'}', device='unix',
type='CHANNEL', specParams='[]', address='{bus=0, controller=0,
type=virtio-serial, port=1}', managed='false', plugged='true',
readOnly='false', deviceAlias='channel0', customProperties='[]',
snapshotId='null', logicalName='null', hostDevice='null'}"},
u'pauseCode': u'NOERR', u'migrationDest': u'libvirt',
u'guestNumaNodes': [{u'nodeIndex': 0, u'cpus': u'0,1',
u'memory': u'2096'}], u'smp': u'2', u'vmType':
u'kvm', u'smpThreadsPerCore': u'1', u'_srcDomXML':
u'<domain type=\'kvm\' id=\'4108\'>\n 
<name>bbgpvmas108</name>\n 
<uuid>a54af7cd-3b89-43c1-82b3-ae0c08d103d3</uuid>\n  <metadata
xmlns:ovirt="http://ovirt.org/vm/tune/1.0">\n    <ovirt:qos/>\n 
</metadata>\n  <maxMemory slots=\'16\'
unit=\'KiB\'>8585216</maxM
 emory>\n  <memory unit=\'KiB\'>2146304</memory>\n 
<currentMemory unit=\'KiB\'>2146304</currentMemory>\n  <vcpu
placement=\'static\' current=\'2\'>16</vcpu>\n  <cputune>\n
   <shares>1020</shares>\n  </cputune>\n  <resource>\n   
<partition>/machine</partition>\n  </resource>\n  <sysinfo
type=\'smbios\'>\n    <system>\n      <entry
name=\'manufacturer\'>oVirt</entry>\n      <entry
name=\'product\'>oVirt Node</entry>\n      <entry
name=\'version\'>7-4.1708.el7.centos</entry>\n      <entry
name=\'serial\'>DF14F0EB-EAAF-33CB-BC4A-4D90DE3A5EEB</entry>\n     
<entry name=\'uuid\'>a54af7cd-3b89-43c1-82b3-ae0c08d103d3</entry>\n   
</system>\n  </sysinfo>\n  <os>\n    <type arch=\'x86_64\'
machine=\'pc-i440fx-rhel7.3.0\'>hvm</type>\n    <smbios
mode=\'sysinfo\'/>\n  </os>\n  <features>\n    <acpi/>\n 
</features>\n  <cpu mode=\'custom\' match=\'exact\'
check=\'full\'>\n    <model
fallback=\'forbid\'>Westmere</model>\n    <topology
sockets=\'16\' cores=\'1\' threads=\'1\'/>\n    <feature
pol
 icy=\'require\' name=\'vme\'/>\n    <feature
policy=\'require\' name=\'pclmuldq\'/>\n    <feature
policy=\'require\' name=\'x2apic\'/>\n    <feature
policy=\'require\' name=\'hypervisor\'/>\n    <feature
policy=\'require\' name=\'arat\'/>\n    <numa>\n      <cell
id=\'0\' cpus=\'0-1\' memory=\'2146304\'
unit=\'KiB\'/>\n    </numa>\n  </cpu>\n  <clock
offset=\'variable\' adjustment=\'0\' basis=\'utc\'>\n   
<timer name=\'rtc\' tickpolicy=\'catchup\'/>\n    <timer
name=\'pit\' tickpolicy=\'delay\'/>\n    <timer
name=\'hpet\' present=\'no\'/>\n  </clock>\n 
<on_poweroff>destroy</on_poweroff>\n 
<on_reboot>restart</on_reboot>\n  <on_crash>destroy</on_crash>\n 
<devices>\n    <emulator>/usr/libexec/qemu-kvm</emulator>\n    <disk
type=\'file\' device=\'cdrom\'>\n      <driver name=\'qemu\'
type=\'raw\'/>\n      <source startupPolicy=\'optional\'/>\n     
<backingStore/>\n      <target dev=\'hdc\' bus=\'ide\'/>\n    
 <readonly/>\n      <alias name=\'ide0-1-0\'/>\n      <address
type=\'dri
 ve\' controller=\'0\' bus=\'1\' target=\'0\'
unit=\'0\'/>\n    </disk>\n    <disk type=\'block\'
device=\'disk\' snapshot=\'no\'>\n      <driver
name=\'qemu\' type=\'raw\' cache=\'none\'
error_policy=\'stop\' io=\'native\'/>\n      <source
dev=\'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/68b8aaff-770d-4a08-800b-0c15e94efaa8/images/1fe4d656-8f59-4221-a859-2f7bcbdb43c3/fbbd2aac-cb7a-471b-b95f-270ce6d00289\'/>\n
     <backingStore/>\n      <target dev=\'vda\'
bus=\'virtio\'/>\n     
<serial>1fe4d656-8f59-4221-a859-2f7bcbdb43c3</serial>\n      <boot
order=\'1\'/>\n      <alias name=\'virtio-disk0\'/>\n     
<address type=\'pci\' domain=\'0x0000\' bus=\'0x00\'
slot=\'0x05\' function=\'0x0\'/>\n    </disk>\n    <controller
type=\'usb\' index=\'0\' model=\'piix3-uhci\'>\n      <alias
name=\'usb\'/>\n      <address type=\'pci\'
domain=\'0x0000\' bus=\'0x00\' slot=\'0x01\'
function=\'0x2\'/>\n    </controller>\n    <controller
type=\'virtio-serial\' index=\'0\' ports=\'16\'>\n   
    <alias name=\'virtio-serial0\'/>\n      <address type=\'pci\'
domain=\'0x0000\' bus=\'0x00\' slot=\'0x04\'
function=\'0x0\'/>\n    </controller>\n    <controller
type=\'pci\' index=\'0\' model=\'pci-root\'>\n      <alias
name=\'pci.0\'/>\n    </controller>\n    <controller
type=\'ide\' index=\'0\'>\n      <alias name=\'ide\'/>\n 
    <address type=\'pci\' domain=\'0x0000\' bus=\'0x00\'
slot=\'0x01\' function=\'0x1\'/>\n    </controller>\n   
<interface type=\'bridge\'>\n      <mac
address=\'00:16:36:4f:bd:df\'/>\n      <source bridge=\'VMs\'/>\n
     <target dev=\'vnet16\'/>\n      <model
type=\'virtio\'/>\n      <filterref
filter=\'vdsm-no-mac-spoofing\'/>\n      <link state=\'up\'/>\n  
   <alias name=\'net0\'/>\n      <address type=\'pci\'
domain=\'0x0000\' bus=\'0x00\' slot=\'0x03\'
function=\'0x0\'/>\n    </interface>\n    <interface
type=\'bridge\'>\n      <mac address=\'00:1a:4a:bd:ed:22\'/>\n   
  <source bridge=\'Backup\'/>\n      <target
dev=\'vnet17\'/>\n      <model t
 ype=\'virtio\'/>\n      <filterref
filter=\'vdsm-no-mac-spoofing\'/>\n      <link state=\'up\'/>\n  
   <alias name=\'net1\'/>\n      <address type=\'pci\'
domain=\'0x0000\' bus=\'0x00\' slot=\'0x07\'
function=\'0x0\'/>\n    </interface>\n    <channel
type=\'unix\'>\n      <source mode=\'bind\'
path=\'/var/lib/libvirt/qemu/channels/a54af7cd-3b89-43c1-82b3-ae0c08d103d3.com.redhat.rhevm.vdsm\'/>\n
     <target type=\'virtio\' name=\'com.redhat.rhevm.vdsm\'
state=\'connected\'/>\n      <alias name=\'channel0\'/>\n     
<address type=\'virtio-serial\' controller=\'0\' bus=\'0\'
port=\'1\'/>\n    </channel>\n    <channel type=\'unix\'>\n
     <source mode=\'bind\'
path=\'/var/lib/libvirt/qemu/channels/a54af7cd-3b89-43c1-82b3-ae0c08d103d3.org.qemu.guest_agent.0\'/>\n
     <target type=\'virtio\' name=\'org.qemu.guest_agent.0\'
state=\'disconnected\'/>\n      <alias name=\'channel1\'/>\n     
<address type=\'virtio-serial\' controller=\'0\' bus=\'0\'
port=\'2\'/>\n    </channel>\n    <inpu
 t type=\'tablet\' bus=\'usb\'>\n      <alias
name=\'input0\'/>\n      <address type=\'usb\' bus=\'0\'
port=\'1\'/>\n    </input>\n    <input type=\'mouse\'
bus=\'ps2\'>\n      <alias name=\'input1\'/>\n   
</input>\n    <input type=\'keyboard\' bus=\'ps2\'>\n     
<alias name=\'input2\'/>\n    </input>\n    <graphics
type=\'vnc\' port=\'5907\' autoport=\'yes\'
listen=\'10.157.8.40\' keymap=\'de\'
passwdValidTo=\'1970-01-01T00:00:01\'>\n      <listen
type=\'network\' address=\'10.157.8.40\'
network=\'vdsm-ovirtmgmt\'/>\n    </graphics>\n    <video>\n     
<model type=\'vga\' vram=\'16384\' heads=\'1\'
primary=\'yes\'/>\n      <alias name=\'video0\'/>\n     
<address type=\'pci\' domain=\'0x0000\' bus=\'0x00\'
slot=\'0x02\' function=\'0x0\'/>\n    </video>\n   
<memballoon model=\'virtio\'>\n      <alias
name=\'balloon0\'/>\n      <address type=\'pci\'
domain=\'0x0000\' bus=\'0x00\' slot=\'0x06\'
function=\'0x0\'/>\n    </memballoon>\n  </devices>\n  <seclabel
type=\'dynamic\' model=\
 'selinux\' relabel=\'yes\'>\n   
<label>system_u:system_r:svirt_t:s0:c76,c549</label>\n   
<imagelabel>system_u:object_r:svirt_image_t:s0:c76,c549</imagelabel>\n 
</seclabel>\n  <seclabel type=\'dynamic\' model=\'dac\'
relabel=\'yes\'>\n    <label>+107:+107</label>\n   
<imagelabel>+107:+107</imagelabel>\n 
</seclabel>\n</domain>\n', u'memSize': 2096,
u'smpCoresPerSocket': u'1', u'vmName': u'bbgpvmas108',
u'nice': u'0', u'username': u'None',
u'maxMemSize': 8384, u'bootMenuEnable': u'false',
u'tabletEnable': u'true', u'smartcardEnable': u'false',
u'clientIp': u'', u'guestFQDN':
u'bbgpvmas108-test.bbg.michelin.com', u'guestAgentAPIVersion': 1,
u'kvmEnable': u'true', u'pitReinjection': u'false',
u'displayNetwork': u'ovirtmgmt', u'devices': [{u'target':
2146304, u'alias': u'balloon0', u'specParams': {u'model':
u'virtio'}, u'deviceId': u'046ac3a6-864d-4d70-9822-484c99b833e5',
u'address': {u'function': u'0x0', u'bus': u'0x00',
u'domain': u'0x0000', u'type': u'pci', u'slot':
u'0x06'}, u'de
 vice': u'memballoon', u'type': u'balloon'},
{u'index': u'0', u'alias': u'usb', u'specParams':
{}, u'deviceId': u'a24b60c7-dbd0-416d-8791-43e101aeaccb',
u'address': {u'slot': u'0x01', u'bus': u'0x00',
u'domain': u'0x0000', u'type': u'pci',
u'function': u'0x2'}, u'device': u'usb', u'model':
u'piix3-uhci', u'type': u'controller'}, {u'alias':
u'virtio-serial0', u'specParams': {}, u'deviceId':
u'c17ebc13-fa7e-4308-937d-77c5e5d4dda9', u'address': {u'slot':
u'0x04', u'bus': u'0x00', u'domain': u'0x0000',
u'type': u'pci', u'function': u'0x0'}, u'device':
u'virtio-serial', u'type': u'controller'}, {u'alias':
u'video0', u'specParams': {u'vram': u'16384'},
u'deviceId': u'240119c6-b3c2-4d08-881b-39ff6fd8ff16', u'address':
{u'slot': u'0x02', u'bus': u'0x00', u'domain':
u'0x0000', u'type': u'pci', u'function': u'0x0'},
u'device': u'vga', u'type': u'video'}, {u'device':
u'vnc', u'specParams': {u'displayNetwork': u'ovirtmgmt',
u'keyMap': u'de', u'displayIp': u'10.157.8.40'},
u'type': u'graphics', u
 'deviceId': u'00000026-0026-0026-0026-000000000175', u'port':
u'5907'}, {u'nicModel': u'pv', u'macAddr':
u'00:16:36:4f:bd:df', u'linkActive': True, u'network':
u'VMs', u'filterParameters': [], u'alias': u'net0',
u'filter': u'vdsm-no-mac-spoofing', u'specParams':
{u'inbound': {}, u'outbound': {}}, u'deviceId':
u'f4a97f85-b60b-4989-81c0-0b3dc1a25be4', u'address': {u'slot':
u'0x03', u'bus': u'0x00', u'domain': u'0x0000',
u'type': u'pci', u'function': u'0x0'}, u'device':
u'bridge', u'type': u'interface', u'name':
u'vnet16'}, {u'nicModel': u'pv', u'macAddr':
u'00:1a:4a:bd:ed:22', u'linkActive': True, u'network':
u'Backup', u'filterParameters': [], u'alias': u'net1',
u'filter': u'vdsm-no-mac-spoofing', u'specParams':
{u'inbound': {}, u'outbound': {}}, u'deviceId':
u'84ce9f2d-fe1b-4529-9998-27d44573947f', u'address': {u'slot':
u'0x07', u'bus': u'0x00', u'domain': u'0x0000',
u'type': u'pci', u'function': u'0x0'}, u'device':
u'bridge', u'type': u'interface', u'name':
u'vnet17'}, {u'index': u
 '2', u'iface': u'ide', u'name': u'hdc',
u'alias': u'ide0-1-0', u'specParams': {u'path':
u''}, u'readonly': u'True', u'deviceId':
u'd9cd7283-a7df-493f-8903-295baf2c8f37', u'address': {u'bus':
u'1', u'controller': u'0', u'type': u'drive',
u'target': u'0', u'unit': u'0'}, u'device':
u'cdrom', u'shared': u'false', u'path': u'',
u'type': u'disk'}, {u'poolID':
u'5849b030-626e-47cb-ad90-3ce782d831b3', u'volumeInfo': {u'path':
u'/rhev/data-center/mnt/blockSD/68b8aaff-770d-4a08-800b-0c15e94efaa8/images/1fe4d656-8f59-4221-a859-2f7bcbdb43c3/fbbd2aac-cb7a-471b-b95f-270ce6d00289',
u'volType': u'path'}, u'index': 0, u'iface':
u'virtio', u'apparentsize': u'53687091200', u'alias':
u'virtio-disk0', u'imageID':
u'1fe4d656-8f59-4221-a859-2f7bcbdb43c3', u'readonly': u'False',
u'shared': u'false', u'truesize': u'53687091200',
u'type': u'disk', u'domainID':
u'68b8aaff-770d-4a08-800b-0c15e94efaa8', u'reqsize': u'0',
u'format': u'raw', u'deviceId':
u'1fe4d656-8f59-4221-a859-2f7bcbdb43c3', u'address': {u'sl
 ot': u'0x05', u'bus': u'0x00', u'domain':
u'0x0000', u'type': u'pci', u'function': u'0x0'},
u'device': u'disk', u'path':
u'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/68b8aaff-770d-4a08-800b-0c15e94efaa8/images/1fe4d656-8f59-4221-a859-2f7bcbdb43c3/fbbd2aac-cb7a-471b-b95f-270ce6d00289',
u'propagateErrors': u'off', u'optional': u'false',
u'name': u'vda', u'bootOrder': u'1', u'volumeID':
u'fbbd2aac-cb7a-471b-b95f-270ce6d00289', u'diskType': u'block',
u'specParams': {}, u'discard': False, u'volumeChain':
[{u'domainID': u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
u'leaseOffset': 164626432, u'volumeID':
u'fbbd2aac-cb7a-471b-b95f-270ce6d00289', u'leasePath':
u'/dev/68b8aaff-770d-4a08-800b-0c15e94efaa8/leases', u'imageID':
u'1fe4d656-8f59-4221-a859-2f7bcbdb43c3', u'path':
u'/rhev/data-center/mnt/blockSD/68b8aaff-770d-4a08-800b-0c15e94efaa8/images/1fe4d656-8f59-4221-a859-2f7bcbdb43c3/fbbd2aac-cb7a-471b-b95f-270ce6d00289'}]},
{u'device': u'ide', u'alias': u'ide', u'type':
u'controller
 ', u'address': {u'slot': u'0x01', u'bus':
u'0x00', u'domain': u'0x0000', u'type': u'pci',
u'function': u'0x1'}}, {u'device': u'unix',
u'alias': u'channel0', u'type': u'channel',
u'address': {u'bus': u'0', u'controller': u'0',
u'type': u'virtio-serial', u'port': u'1'}},
{u'device': u'unix', u'alias': u'channel1',
u'type': u'channel', u'address': {u'bus': u'0',
u'controller': u'0', u'type': u'virtio-serial',
u'port': u'2'}}, {u'device': u'tablet', u'alias':
u'input0', u'type': u'input', u'address': {u'bus':
u'0', u'type': u'usb', u'port': u'1'}}],
u'memGuaranteedSize': 1024, u'maxVCpus': u'16',
u'guestIPs': u'10.157.11.88', u'statusTime':
u'12083235990', u'maxMemSlots': 16}, recover=False)
from=::ffff:10.157.8.40,35732 (api:46)
2018-06-28 12:25:49,278+0200 INFO  (jsonrpc/4) [vdsm.api] FINISH __init__ return=None
from=::ffff:10.157.8.40,35732 (api:52)
2018-06-28 12:25:49,281+0200 INFO  (vm/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') VM wrapper has started (vm:1968)
2018-06-28 12:25:49,282+0200 WARN  (vm/a54af7cd) [virt.vm]
(vmId='a54af7cd-3b89-43c1-82b3-ae0c08d103d3') Unknown type found, device:
'{u'device': u'tablet', u'alias': u'input0',
u'type': u'input', u'address': {u'bus': u'0',
u'type': u'usb', u'port': u'1'}}' found (vm:452)
2018-06-28 12:25:49,282+0200 INFO  (vm/a54af7cd) [vdsm.api] START
getVolumeSize(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'1fe4d656-8f59-4221-a859-2f7bcbdb43c3',
volUUID=u'fbbd2aac-cb7a-471b-b95f-270ce6d00289', options=None) from=internal,
task_id=83e1bc92-a406-4b05-abc1-ef6c476435e5 (api:46)
2018-06-28 12:25:49,354+0200 INFO  (vm/a54af7cd) [vdsm.api] FINISH getVolumeSize
return={'truesize': '53687091200', 'apparentsize':
'53687091200'} from=internal, task_id=83e1bc92-a406-4b05-abc1-ef6c476435e5
(api:52)
2018-06-28 12:25:49,355+0200 INFO  (vm/a54af7cd) [vds] prepared volume path: 
(clientIF:380)
2018-06-28 12:25:49,356+0200 INFO  (vm/a54af7cd) [vdsm.api] START
prepareImage(sdUUID=u'68b8aaff-770d-4a08-800b-0c15e94efaa8',
spUUID=u'5849b030-626e-47cb-ad90-3ce782d831b3',
imgUUID=u'1fe4d656-8f59-4221-a859-2f7bcbdb43c3',
leafUUID=u'fbbd2aac-cb7a-471b-b95f-270ce6d00289', allowIllegal=False)
from=internal, task_id=186f0bc0-58e0-48a6-b0bc-c7b9b7dfb19e (api:46)
2018-06-28 12:25:49,428+0200 INFO  (vm/a54af7cd) [storage.LVM] Activating lvs:
vg=68b8aaff-770d-4a08-800b-0c15e94efaa8
lvs=['fbbd2aac-cb7a-471b-b95f-270ce6d00289'] (lvm:1295)
2018-06-28 12:25:49,720+0200 INFO  (vm/a54af7cd) [storage.LVM] Refreshing lvs:
vg=68b8aaff-770d-4a08-800b-0c15e94efaa8 lvs=['leases'] (lvm:1291)
2018-06-28 12:25:49,720+0200 INFO  (vm/a54af7cd) [storage.LVM] Refreshing LVs
(vg=68b8aaff-770d-4a08-800b-0c15e94efaa8, lvs=['leases']) (lvm:1319)
2018-06-28 12:25:49,812+0200 INFO  (vm/a54af7cd) [vdsm.api] FINISH prepareImage
return={'info': {'path':
u'/rhev/data-center/mnt/blockSD/68b8aaff-770d-4a08-800b-0c15e94efaa8/images/1fe4d656-8f59-4221-a859-2f7bcbdb43c3/fbbd2aac-cb7a-471b-b95f-270ce6d00289',
'volType': 'path'}, 'path':
u'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/68b8aaff-770d-4a08-800b-0c15e94efaa8/images/1fe4d656-8f59-4221-a859-2f7bcbdb43c3/fbbd2aac-cb7a-471b-b95f-270ce6d00289',
'imgVolumesInfo': [{'domainID':
u'68b8aaff-770d-4a08-800b-0c15e94efaa8', 'leaseOffset': 164626432,
'path':
u'/rhev/data-center/mnt/blockSD/68b8aaff-770d-4a08-800b-0c15e94efaa8/images/1fe4d656-8f59-4221-a859-2f7bcbdb43c3/fbbd2aac-cb7a-471b-b95f-270ce6d00289',
'volumeID': 'fbbd2aac-cb7a-471b-b95f-270ce6d00289', 'leasePath':
'/dev/68b8aaff-770d-4a08-800b-0c15e94efaa8/leases', 'imageID':
u'1fe4d656-8f59-4221-a859-2f7bcbdb43c3'}]} from=internal,
task_id=186f0bc0-58e0-48a6-b0bc-c7b9b7dfb19e (api:52)
2018-06-28 12:25:49,814+0200 INFO  (vm/a54af7cd) [vds] prepared volume path:
/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/68b8aaff-770d-4a08-800b-0c15e94efaa8/images/1fe4d656-8f59-4221-a859-2f7bcbdb43c3/fbbd2aac-cb7a-471b-b95f-270ce6d00289
(clientIF:380)
2018-06-28 12:25:49,857+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call
VM.migrationCreate succeeded in 0.60 seconds (__init__:539)
2018-06-28 12:25:55,791+0200 INFO  (itmap/0) [IOProcessClient] Starting client
ioprocess-78498 (__init__:330)
2018-06-28 12:25:55,803+0200 INFO  (ioprocess/3512) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:25:55,804+0200 INFO  (itmap/1) [IOProcessClient] Starting client
ioprocess-78499 (__init__:330)
2018-06-28 12:25:55,812+0200 INFO  (itmap/2) [IOProcessClient] Starting client
ioprocess-78500 (__init__:330)
2018-06-28 12:25:55,817+0200 INFO  (ioprocess/3527) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:25:55,822+0200 INFO  (ioprocess/3533) [IOProcess] Starting ioprocess
(__init__:452)
2018-06-28 12:25:55,832+0200 INFO  (monitor/48055e2) [storage.StorageDomain] Resource
namespace 01_img_48055e27-f1ca-466a-8a2c-e191c34f0226 already registered (sd:758)
2018-06-28 12:25:55,832+0200 INFO  (monitor/48055e2) [storage.StorageDomain] Resource
namespace 02_vol_48055e27-f1ca-466a-8a2c-e191c34f0226 already registered (sd:767)
2018-06-28 12:25:55,836+0200 INFO  (monitor/b5ae41a) [storage.StorageDomain] Resource
namespace 01_img_b5ae41ac-7318-4748-9346-b08d8e5a9248 already registered (sd:758)
2018-06-28 12:25:55,836+0200 INFO  (monitor/b5ae41a) [storage.StorageDomain] Resource
namespace 02_vol_b5ae41ac-7318-4748-9346-b08d8e5a9248 already registered (sd:767)
2018-06-28 12:25:58,400+0200 INFO  (jsonrpc/5) [vdsm.api] START
setBalloonTarget(target=9817245) from=::1,46990 (api:46)
2018-06-28 12:25:58,417+0200 INFO  (jsonrpc/5) [vdsm.api] FINISH setBalloonTarget
return={'status': {'message': 'Done', 'code': 0}}
from=::1,46990 (api:52)
2018-06-28 12:25:58,417+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
VM.setBalloonTarget succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:25:58,658+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
2018-06-28 12:25:59,959+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
2018-06-28 12:25:59,979+0200 ERROR (jsonrpc/6) [jsonrpc.JsonRpcServer] Internal server
error (__init__:577)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 572, in
_handle_request
    res = method(**params)
  File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 202, in
_dynamicMethod
    result = fn(*methodArgs)
  File "/usr/share/vdsm/API.py", line 1454, in getAllVmIoTunePolicies
    io_tune_policies_dict = self._cif.getAllVmIoTunePolicies()
  File "/usr/share/vdsm/clientIF.py", line 454, in getAllVmIoTunePolicies
    'current_values': v.getIoTune()}
  File "/usr/share/vdsm/virt/vm.py", line 2859, in getIoTune
    result = self.getIoTuneResponse()
  File "/usr/share/vdsm/virt/vm.py", line 2878, in getIoTuneResponse
    res = self._dom.blockIoTune(
  File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line 47, in
__getattr__
    % self.vmid)
NotConnectedError: VM u'a54af7cd-3b89-43c1-82b3-ae0c08d103d3' was not started yet
or was shut down
2018-06-28 12:25:59,981+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmIoTunePolicies failed (error -32603) in 0.00 seconds (__init__:539)
2018-06-28 12:26:02,275+0200 INFO  (periodic/6160) [vdsm.api] START
repoStats(options=None) from=internal, task_id=0fc8eaea-80b5-4a7d-aa70-78681613e5c6
(api:46)
2018-06-28 12:26:02,276+0200 INFO  (periodic/6160) [vdsm.api] FINISH repoStats
return={u'48055e27-f1ca-466a-8a2c-e191c34f0226': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.000506027', 'lastCheck': '0.9', 'valid': True},
u'b5ae41ac-7318-4748-9346-b08d8e5a9248': {'code': 0, 'actual':
True, 'version': 0, 'acquired': True, 'delay':
'0.000616951', 'lastCheck': '4.0', 'valid': True},
u'68b8aaff-770d-4a08-800b-0c15e94efaa8': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000293051', 'lastCheck': '4.1', 'valid': True},
u'8924ce27-14b9-4ef8-ad10-8c0ebb83e2e5': {'code': 0, 'actual':
True, 'version': 4, 'acquired': True, 'delay':
'0.000381327', 'lastCheck': '1.9', 'valid': True}}
from=internal, task_id=0fc8eaea-80b5-4a7d-aa70-78681613e5c6 (api:52)

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

[ovirt-users] Re: Unable to do Live Migration