Re: [ovirt-users] Error during delete snapshot

Monday, 27 November 2017

Problem Solved.

I created a new snapshot, then, I get the id and replaced in the database.
So I deleted and problem solved. ;)

Atenciosamente,
Arthur Melo
Linux User #302250

2017-11-24 16:08 GMT-02:00 Arthur Melo <arthur(a)afabrica.net&gt;:

...
 Sorry for delay.

 I think the problem is on the oVirt Engine, by the way, the files are
 attached.

 Atenciosamente,
 Arthur Melo
 Linux User #302250

 2017-11-22 11:29 GMT-02:00 Benny Zlotnik <bzlotnik(a)redhat.com&gt;:

> I cannot see the error in the VDSM, please attach the full logs (you can
> compress them and attach a file)
>
> On Tue, Nov 21, 2017 at 2:36 PM, Arthur Melo <arthur(a)afabrica.net&gt; wrote:
>
>> I don't have vdsm.log at the engine machine.
>>
>> vdsm.log (host03, where proxy03 is located on)
>>
>> 2017-11-21 10:32:48,340-0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:32:48,392-0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:32:53,725-0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)
>> 2017-11-21 10:32:54,219-0200 INFO  (periodic/343) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=a5c36747-92b8-4659-a64c-5d3b14b7a5fd
>> (api:46)
>> 2017-11-21 10:32:54,219-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00043105',
>> 'lastCheck': '6.4', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00787006', 'lastCheck': '6.5', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.0169619', 'lastCheck': '7.5',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00485451',
>> 'lastCheck': '6.5', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000404865', 'lastCheck': '6.4', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000347603', 'lastCheck': '3.0',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000443444',
>> 'lastCheck': '7.4', 'valid': True}} from=internal,
>> task_id=a5c36747-92b8-4659-a64c-5d3b14b7a5fd (api:52)
>> 2017-11-21 10:33:01,181-0200 INFO  (monitor/0048460) [IOProcessClient]
>> Closing client ioprocess-11887 (__init__:598)
>> 2017-11-21 10:33:01,182-0200 INFO  (monitor/0048460) [IOProcessClient]
>> Closing client ioprocess-11886 (__init__:598)
>> 2017-11-21 10:33:01,867-0200 INFO  (jsonrpc/1) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=46b3675a, task_id=57a40d25-9994-4a9c-9531-a3c2476516e1 (api:46)
>> 2017-11-21 10:33:01,867-0200 INFO  (jsonrpc/1) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000399937',
>> 'lastCheck': '4.1', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00974892', 'lastCheck': '4.2', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00352112', 'lastCheck': '5.1',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000560259',
>> 'lastCheck': '4.1', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000447462', 'lastCheck': '4.0', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000477881', 'lastCheck': '0.7',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000480301',
>> 'lastCheck': '5.0', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=46b3675a, task_id=57a40d25-9994-4a9c-9531-a3c2476516e1 (api:52)
>> 2017-11-21 10:33:01,915-0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.05 seconds (__init__:539)
>> 2017-11-21 10:33:03,421-0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
>> 2017-11-21 10:33:03,442-0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:33:08,805-0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)
>> 2017-11-21 10:33:09,307-0200 INFO  (periodic/343) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=c844a4cb-22df-4b0d-ad0f-0b6edc48f048
>> (api:46)
>> 2017-11-21 10:33:09,308-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000421227',
>> 'lastCheck': '1.5', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.0113034', 'lastCheck': '1.6', 'valid': True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.0227581', 'lastCheck': '2.6',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.0142187',
>> 'lastCheck': '1.6', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000430952', 'lastCheck': '1.5', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000477881', 'lastCheck': '8.1',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000346374',
>> 'lastCheck': '2.4', 'valid': True}} from=internal,
>> task_id=c844a4cb-22df-4b0d-ad0f-0b6edc48f048 (api:52)
>> 2017-11-21 10:33:16,108-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'aeee6368-45bb-4a98-937b-587aab3daec3',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'046588d2-0d5d-4901-afb4-5902f3e9a7b1',
>> volUUID='80ee1579-fa6c-4c8a-bbe1-3ead1c8b28f9', options=None)
>> from=internal, task_id=f7ce7918-fa47-45c3-8c26-30325d0a6dc9 (api:46)
>> 2017-11-21 10:33:16,109-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '53687091200',
'apparentsize':
>> '53687091200'} from=internal,
task_id=f7ce7918-fa47-45c3-8c26-30325d0a6dc9
>> (api:52)
>> 2017-11-21 10:33:16,111-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'0f7db06e-7f03-46a5-98c6-264106ad640a',
>> volUUID=u'dc8248bd-fa5d-4627-ad93-d91b6d55090c', options=None)
>> from=internal, task_id=8533e798-a80b-4334-a885-afdc4cc0ebc5 (api:46)
>> 2017-11-21 10:33:16,111-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=8533e798-a80b-4334-a885-afdc4cc0ebc5
>> (api:52)
>> 2017-11-21 10:33:16,113-0200 INFO  (periodic/343) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'12eddfe8-e706-4204-95ee-d3ff01bf0db5',
>> volUUID='9b607027-7401-494f-9b48-40d6a3e4abec', options=None)
>> from=internal, task_id=580f8cae-e632-4297-8b0f-0b917d8b3c72 (api:46)
>> 2017-11-21 10:33:16,113-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=580f8cae-e632-4297-8b0f-0b917d8b3c72
>> (api:52)
>> 2017-11-21 10:33:16,114-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'562ca0c9-60b2-419d-aaa2-df6ff10292f6',
>> volUUID='9181c596-93b0-43df-8ab1-b1ee4cb9721b', options=None)
>> from=internal, task_id=e09822f1-8d61-42c7-bed0-c9be3295996e (api:46)
>> 2017-11-21 10:33:16,115-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '11811160064',
'apparentsize':
>> '11811160064'} from=internal,
task_id=e09822f1-8d61-42c7-bed0-c9be3295996e
>> (api:52)
>> 2017-11-21 10:33:16,116-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'bd0c6749-538e-4299-891f-f35da6d8a4a3',
>> volUUID='d95b1638-f829-4264-8667-cd68f26783c0', options=None)
>> from=internal, task_id=f4ecbc87-f805-42e3-a708-f7fdc7c0abff (api:46)
>> 2017-11-21 10:33:16,117-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=f4ecbc87-f805-42e3-a708-f7fdc7c0abff
>> (api:52)
>> 2017-11-21 10:33:16,118-0200 INFO  (periodic/343) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'ca424d56-f294-48fb-a627-72dac02ec315',
>> volUUID='f241aba7-3ae4-432b-b55c-9ba95ce10e2c', options=None)
>> from=internal, task_id=85313846-51a8-4c5f-ae64-ca3b923882d9 (api:46)
>> 2017-11-21 10:33:16,118-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '35433480192',
'apparentsize':
>> '35433480192'} from=internal,
task_id=85313846-51a8-4c5f-ae64-ca3b923882d9
>> (api:52)
>> 2017-11-21 10:33:16,120-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'c0327f75-15d3-4aa2-9819-da48694183e2',
>> volUUID='3b846bd2-6698-4cf9-871a-4c867a0fc30f', options=None)
>> from=internal, task_id=3e704259-a21b-41bb-9a20-2c195ffb8751 (api:46)
>> 2017-11-21 10:33:16,120-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '64424509440',
'apparentsize':
>> '64424509440'} from=internal,
task_id=3e704259-a21b-41bb-9a20-2c195ffb8751
>> (api:52)
>> 2017-11-21 10:33:16,121-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'5c33574c-9b4b-432d-b61e-62bac8c155fd',
>> volUUID='1ddb9ebc-5c6b-4e73-bc2a-3e9983cf9a73', options=None)
>> from=internal, task_id=b014dfd6-2fc2-4b86-9d14-4d58213d3470 (api:46)
>> 2017-11-21 10:33:16,122-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=b014dfd6-2fc2-4b86-9d14-4d58213d3470
>> (api:52)
>> 2017-11-21 10:33:16,123-0200 INFO  (periodic/343) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'36bf11d9-5456-4f69-8719-35ed6e0fb305',
>> volUUID='083b0e95-6b45-4904-92be-b1eba0af4289', options=None)
>> from=internal, task_id=8c1aa585-ed1d-43d4-a707-1249c9d8ec2a (api:46)
>> 2017-11-21 10:33:16,123-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '42949672960',
'apparentsize':
>> '42949672960'} from=internal,
task_id=8c1aa585-ed1d-43d4-a707-1249c9d8ec2a
>> (api:52)
>> 2017-11-21 10:33:16,124-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'd68942d0-2ee1-48f5-8f14-580b917e835d',
>> volUUID='5997ab7a-2be3-4790-a9b4-5572da3eeb24', options=None)
>> from=internal, task_id=815cf337-24d4-4d73-8a1a-ad095547e711 (api:46)
>> 2017-11-21 10:33:16,124-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=815cf337-24d4-4d73-8a1a-ad095547e711
>> (api:52)
>> 2017-11-21 10:33:16,125-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'4fd0ce51-815a-457d-bfd9-1d2c0c2a3f0c',
>> volUUID='e5415881-1bdd-40cc-b2bb-447cfdffd762', options=None)
>> from=internal, task_id=4b3a0d06-44c6-4f8d-ae66-d0c66d8e69cd (api:46)
>> 2017-11-21 10:33:16,126-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=4b3a0d06-44c6-4f8d-ae66-d0c66d8e69cd
>> (api:52)
>> 2017-11-21 10:33:16,127-0200 INFO  (periodic/343) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'ae5b7335-0234-4d39-8b0d-eaa57f3247be',
>> volUUID='b118bb04-c580-49e8-b24d-864f3640fbca', options=None)
>> from=internal, task_id=3600445f-7535-4e10-8036-1d42ff8ada91 (api:46)
>> 2017-11-21 10:33:16,127-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=3600445f-7535-4e10-8036-1d42ff8ada91
>> (api:52)
>> 2017-11-21 10:33:16,128-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'50e17b7b-3a86-4797-9c42-8f4562fbf7a5',
>> volUUID='902db022-3300-45d0-9bdc-58c0a2ee7dbc', options=None)
>> from=internal, task_id=012e4d7b-cab1-4a0e-85bc-12e7cb4e8e24 (api:46)
>> 2017-11-21 10:33:16,128-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=012e4d7b-cab1-4a0e-85bc-12e7cb4e8e24
>> (api:52)
>> 2017-11-21 10:33:16,129-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'a48e6b30-7d29-477e-8b94-a2a4ecd83c98',
>> volUUID='e4a1e27c-4dad-4735-861c-569cba9bc46f', options=None)
>> from=internal, task_id=5544b693-031a-4f7a-8972-37ea02623084 (api:46)
>> 2017-11-21 10:33:16,129-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '39728447488',
'apparentsize':
>> '39728447488'} from=internal,
task_id=5544b693-031a-4f7a-8972-37ea02623084
>> (api:52)
>> 2017-11-21 10:33:16,130-0200 INFO  (periodic/343) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'd8d02bb5-be37-45f2-aaaa-2f28e4fcca25',
>> volUUID='c1c7bb81-6dae-4b1d-a514-4ec5de053994', options=None)
>> from=internal, task_id=f274c966-dd29-4169-9dfe-5a05e82c5e01 (api:46)
>> 2017-11-21 10:33:16,131-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '107374182400',
'apparentsize':
>> '107374182400'} from=internal,
task_id=f274c966-dd29-4169-9dfe-5a05e82c5e01
>> (api:52)
>> 2017-11-21 10:33:16,132-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'f0886b2c-52d4-4f16-9a90-2fdf96d0fb6b',
>> volUUID='235b33f4-923c-4cad-91aa-60e36cae15c3', options=None)
>> from=internal, task_id=addf386d-3769-4bd5-bc31-acfbcd29c828 (api:46)
>> 2017-11-21 10:33:16,133-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=addf386d-3769-4bd5-bc31-acfbcd29c828
>> (api:52)
>> 2017-11-21 10:33:16,966-0200 INFO  (jsonrpc/3) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=19fb22c2, task_id=68319311-5407-4559-9611-61f6277cfba1 (api:46)
>> 2017-11-21 10:33:16,967-0200 INFO  (jsonrpc/3) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000421227',
>> 'lastCheck': '1.1', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.0113034', 'lastCheck': '1.1', 'valid': True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00619586', 'lastCheck': '0.2',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.0142187',
>> 'lastCheck': '1.0', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000430952', 'lastCheck': '1.2', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.00031821', 'lastCheck': '5.8',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000494404',
>> 'lastCheck': '0.1', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=19fb22c2, task_id=68319311-5407-4559-9611-61f6277cfba1 (api:52)
>> 2017-11-21 10:33:17,009-0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.04 seconds (__init__:539)
>> 2017-11-21 10:33:18,475-0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:33:18,524-0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.01 seconds
>> (__init__:539)
>> 2017-11-21 10:33:23,871-0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
>> 2017-11-21 10:33:24,402-0200 INFO  (periodic/342) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=8dd40afb-b051-402d-a39f-8b47eb3788a1
>> (api:46)
>> 2017-11-21 10:33:24,402-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000538929',
>> 'lastCheck': '6.6', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.014852', 'lastCheck': '6.7', 'valid': True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00619586', 'lastCheck': '7.7',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00615694',
>> 'lastCheck': '6.7', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000408817', 'lastCheck': '6.6', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000499266', 'lastCheck': '3.2',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000494404',
>> 'lastCheck': '7.5', 'valid': True}} from=internal,
>> task_id=8dd40afb-b051-402d-a39f-8b47eb3788a1 (api:52)
>> 2017-11-21 10:33:32,108-0200 INFO  (jsonrpc/1) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=5e2763e4, task_id=b06ce104-bb68-40dd-886e-6bc0e27be511 (api:46)
>> 2017-11-21 10:33:32,109-0200 INFO  (jsonrpc/1) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000436164',
>> 'lastCheck': '4.3', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.0155751', 'lastCheck': '4.4', 'valid': True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.0195332', 'lastCheck': '5.4',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00680802',
>> 'lastCheck': '4.3', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000406155', 'lastCheck': '4.3', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000350002', 'lastCheck': '0.9',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000463385',
>> 'lastCheck': '5.3', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=5e2763e4, task_id=b06ce104-bb68-40dd-886e-6bc0e27be511 (api:52)
>> 2017-11-21 10:33:32,166-0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.06 seconds (__init__:539)
>> 2017-11-21 10:33:33,540-0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.01 seconds (__init__:539)
>> 2017-11-21 10:33:33,561-0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:33:35,705-0200 INFO  (itmap/0) [IOProcessClient] Starting
>> client ioprocess-11888 (__init__:330)
>> 2017-11-21 10:33:35,729-0200 INFO  (itmap/1) [IOProcessClient] Starting
>> client ioprocess-11889 (__init__:330)
>> 2017-11-21 10:33:35,752-0200 INFO  (ioprocess/20559) [IOProcess]
>> Starting ioprocess (__init__:452)
>> 2017-11-21 10:33:35,757-0200 INFO  (ioprocess/20565) [IOProcess]
>> Starting ioprocess (__init__:452)
>> 2017-11-21 10:33:35,765-0200 INFO  (monitor/133d2fb)
>> [storage.StorageDomain] Resource namespace
01_img_133d2fbd-b905-45f8-860a-cd3e72f3f49d
>> already registered (sd:727)
>> 2017-11-21 10:33:35,765-0200 INFO  (monitor/133d2fb)
>> [storage.StorageDomain] Resource namespace
02_vol_133d2fbd-b905-45f8-860a-cd3e72f3f49d
>> already registered (sd:736)
>> 2017-11-21 10:33:38,944-0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)
>> 2017-11-21 10:33:39,535-0200 INFO  (periodic/344) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=e82beb91-82d2-4d17-957b-5e0887a0824d
>> (api:46)
>> 2017-11-21 10:33:39,535-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000450668',
>> 'lastCheck': '1.7', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000602672', 'lastCheck': '1.8', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.000958537', 'lastCheck': '2.9',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000524798',
>> 'lastCheck': '1.8', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000431355', 'lastCheck': '1.7', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000350002', 'lastCheck': '8.3',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000406714',
>> 'lastCheck': '2.7', 'valid': True}} from=internal,
>> task_id=e82beb91-82d2-4d17-957b-5e0887a0824d (api:52)
>> 2017-11-21 10:33:47,213-0200 INFO  (jsonrpc/3) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=4aaa55b3, task_id=0ccfc73e-4876-436a-8eb7-4f32b4ea2dd7 (api:46)
>> 2017-11-21 10:33:47,214-0200 INFO  (jsonrpc/3) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000450668',
>> 'lastCheck': '1.3', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000602672', 'lastCheck': '1.3', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00734942', 'lastCheck': '0.5',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000524798',
>> 'lastCheck': '1.2', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000431355', 'lastCheck': '1.4', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.00034744', 'lastCheck': '6.0',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000485543',
>> 'lastCheck': '0.3', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=4aaa55b3, task_id=0ccfc73e-4876-436a-8eb7-4f32b4ea2dd7 (api:52)
>> 2017-11-21 10:33:47,255-0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.05 seconds (__init__:539)
>> 2017-11-21 10:33:48,593-0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:33:48,633-0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.01 seconds
>> (__init__:539)
>> 2017-11-21 10:33:54,016-0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)
>> 2017-11-21 10:33:54,650-0200 INFO  (periodic/341) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=b22332d1-1cd2-417d-bf83-637a711ce467
>> (api:46)
>> 2017-11-21 10:33:54,650-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00188248',
>> 'lastCheck': '6.8', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00292128', 'lastCheck': '7.0', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00734942', 'lastCheck': '8.0',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.005357',
>> 'lastCheck': '6.9', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000389392', 'lastCheck': '6.8', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000338751', 'lastCheck': '3.5',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000485543',
>> 'lastCheck': '7.8', 'valid': True}} from=internal,
>> task_id=b22332d1-1cd2-417d-bf83-637a711ce467 (api:52)
>> 2017-11-21 10:34:02,316-0200 INFO  (jsonrpc/1) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=fe4bc0a, task_id=a4eda238-199c-4346-a941-8f0a5f2e7133 (api:46)
>> 2017-11-21 10:34:02,317-0200 INFO  (jsonrpc/1) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000481169',
>> 'lastCheck': '4.5', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00467249', 'lastCheck': '4.6', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00584804', 'lastCheck': '5.6',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00652665',
>> 'lastCheck': '4.6', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000449782', 'lastCheck': '4.5', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000409327', 'lastCheck': '1.1',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.00046967',
>> 'lastCheck': '5.5', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=fe4bc0a, task_id=a4eda238-199c-4346-a941-8f0a5f2e7133 (api:52)
>> 2017-11-21 10:34:02,377-0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.06 seconds (__init__:539)
>> 2017-11-21 10:34:03,655-0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:34:03,675-0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:34:09,093-0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:34:09,733-0200 INFO  (periodic/344) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=b79c478b-c40a-4e0e-8aad-d7bf7271a1ad
>> (api:46)
>> 2017-11-21 10:34:09,734-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000501576',
>> 'lastCheck': '1.9', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00316746', 'lastCheck': '2.0', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00681892', 'lastCheck': '3.0',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00840636',
>> 'lastCheck': '2.0', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000503123', 'lastCheck': '1.9', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000342223', 'lastCheck': '0.2',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000551599',
>> 'lastCheck': '2.9', 'valid': True}} from=internal,
>> task_id=b79c478b-c40a-4e0e-8aad-d7bf7271a1ad (api:52)
>> 2017-11-21 10:34:16,114-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'aeee6368-45bb-4a98-937b-587aab3daec3',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'046588d2-0d5d-4901-afb4-5902f3e9a7b1',
>> volUUID='80ee1579-fa6c-4c8a-bbe1-3ead1c8b28f9', options=None)
>> from=internal, task_id=09750ed6-c691-4c61-817a-596b126d0e0a (api:46)
>> 2017-11-21 10:34:16,115-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '53687091200',
'apparentsize':
>> '53687091200'} from=internal,
task_id=09750ed6-c691-4c61-817a-596b126d0e0a
>> (api:52)
>> 2017-11-21 10:34:16,116-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'0f7db06e-7f03-46a5-98c6-264106ad640a',
>> volUUID=u'dc8248bd-fa5d-4627-ad93-d91b6d55090c', options=None)
>> from=internal, task_id=68c8aa9a-fb36-498e-bfeb-acb58da56c9c (api:46)
>> 2017-11-21 10:34:16,117-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=68c8aa9a-fb36-498e-bfeb-acb58da56c9c
>> (api:52)
>> 2017-11-21 10:34:16,118-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'12eddfe8-e706-4204-95ee-d3ff01bf0db5',
>> volUUID='9b607027-7401-494f-9b48-40d6a3e4abec', options=None)
>> from=internal, task_id=fafccdb4-06b8-4442-a01f-46c87c04b696 (api:46)
>> 2017-11-21 10:34:16,119-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=fafccdb4-06b8-4442-a01f-46c87c04b696
>> (api:52)
>> 2017-11-21 10:34:16,120-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'562ca0c9-60b2-419d-aaa2-df6ff10292f6',
>> volUUID='9181c596-93b0-43df-8ab1-b1ee4cb9721b', options=None)
>> from=internal, task_id=a8e36efd-c050-43aa-9e3d-88fe42b2fb7a (api:46)
>> 2017-11-21 10:34:16,120-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '11811160064',
'apparentsize':
>> '11811160064'} from=internal,
task_id=a8e36efd-c050-43aa-9e3d-88fe42b2fb7a
>> (api:52)
>> 2017-11-21 10:34:16,121-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'bd0c6749-538e-4299-891f-f35da6d8a4a3',
>> volUUID='d95b1638-f829-4264-8667-cd68f26783c0', options=None)
>> from=internal, task_id=2ec682b8-e99b-4383-b917-99e3651dc9d7 (api:46)
>> 2017-11-21 10:34:16,122-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=2ec682b8-e99b-4383-b917-99e3651dc9d7
>> (api:52)
>> 2017-11-21 10:34:16,122-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'ca424d56-f294-48fb-a627-72dac02ec315',
>> volUUID='f241aba7-3ae4-432b-b55c-9ba95ce10e2c', options=None)
>> from=internal, task_id=78b3c805-a930-4b63-acad-99178112758a (api:46)
>> 2017-11-21 10:34:16,123-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '35433480192',
'apparentsize':
>> '35433480192'} from=internal,
task_id=78b3c805-a930-4b63-acad-99178112758a
>> (api:52)
>> 2017-11-21 10:34:16,124-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'c0327f75-15d3-4aa2-9819-da48694183e2',
>> volUUID='3b846bd2-6698-4cf9-871a-4c867a0fc30f', options=None)
>> from=internal, task_id=3a243657-8264-4c06-ae57-1023ac16bd07 (api:46)
>> 2017-11-21 10:34:16,124-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '64424509440',
'apparentsize':
>> '64424509440'} from=internal,
task_id=3a243657-8264-4c06-ae57-1023ac16bd07
>> (api:52)
>> 2017-11-21 10:34:16,125-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'5c33574c-9b4b-432d-b61e-62bac8c155fd',
>> volUUID='1ddb9ebc-5c6b-4e73-bc2a-3e9983cf9a73', options=None)
>> from=internal, task_id=c6993c71-d2d5-41bd-9000-ccd5b6d4954c (api:46)
>> 2017-11-21 10:34:16,125-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=c6993c71-d2d5-41bd-9000-ccd5b6d4954c
>> (api:52)
>> 2017-11-21 10:34:16,126-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'36bf11d9-5456-4f69-8719-35ed6e0fb305',
>> volUUID='083b0e95-6b45-4904-92be-b1eba0af4289', options=None)
>> from=internal, task_id=5bd3e2e2-9410-4aa5-8ae2-07b36b5f0ec2 (api:46)
>> 2017-11-21 10:34:16,126-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '42949672960',
'apparentsize':
>> '42949672960'} from=internal,
task_id=5bd3e2e2-9410-4aa5-8ae2-07b36b5f0ec2
>> (api:52)
>> 2017-11-21 10:34:16,127-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'd68942d0-2ee1-48f5-8f14-580b917e835d',
>> volUUID='5997ab7a-2be3-4790-a9b4-5572da3eeb24', options=None)
>> from=internal, task_id=768ec546-bf3b-405a-992d-0c7a0e3f1e7f (api:46)
>> 2017-11-21 10:34:16,128-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=768ec546-bf3b-405a-992d-0c7a0e3f1e7f
>> (api:52)
>> 2017-11-21 10:34:16,128-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'4fd0ce51-815a-457d-bfd9-1d2c0c2a3f0c',
>> volUUID='e5415881-1bdd-40cc-b2bb-447cfdffd762', options=None)
>> from=internal, task_id=b238b726-7bd7-4f3c-8198-0139f96c7e16 (api:46)
>> 2017-11-21 10:34:16,129-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=b238b726-7bd7-4f3c-8198-0139f96c7e16
>> (api:52)
>> 2017-11-21 10:34:16,130-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'ae5b7335-0234-4d39-8b0d-eaa57f3247be',
>> volUUID='b118bb04-c580-49e8-b24d-864f3640fbca', options=None)
>> from=internal, task_id=734612f4-7e27-4533-8726-313f79bf5c6d (api:46)
>> 2017-11-21 10:34:16,130-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=734612f4-7e27-4533-8726-313f79bf5c6d
>> (api:52)
>> 2017-11-21 10:34:16,131-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'50e17b7b-3a86-4797-9c42-8f4562fbf7a5',
>> volUUID='902db022-3300-45d0-9bdc-58c0a2ee7dbc', options=None)
>> from=internal, task_id=b412232b-1634-48b9-87c8-486620f1da8a (api:46)
>> 2017-11-21 10:34:16,131-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=b412232b-1634-48b9-87c8-486620f1da8a
>> (api:52)
>> 2017-11-21 10:34:16,132-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'a48e6b30-7d29-477e-8b94-a2a4ecd83c98',
>> volUUID='e4a1e27c-4dad-4735-861c-569cba9bc46f', options=None)
>> from=internal, task_id=fd3faa5c-db77-463d-82a7-be811cbe40ea (api:46)
>> 2017-11-21 10:34:16,132-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '39728447488',
'apparentsize':
>> '39728447488'} from=internal,
task_id=fd3faa5c-db77-463d-82a7-be811cbe40ea
>> (api:52)
>> 2017-11-21 10:34:16,133-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'd8d02bb5-be37-45f2-aaaa-2f28e4fcca25',
>> volUUID='c1c7bb81-6dae-4b1d-a514-4ec5de053994', options=None)
>> from=internal, task_id=54a8abaa-8a2b-454e-866f-616c4c7a309b (api:46)
>> 2017-11-21 10:34:16,133-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '107374182400',
'apparentsize':
>> '107374182400'} from=internal,
task_id=54a8abaa-8a2b-454e-866f-616c4c7a309b
>> (api:52)
>> 2017-11-21 10:34:16,134-0200 INFO  (periodic/343) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'f0886b2c-52d4-4f16-9a90-2fdf96d0fb6b',
>> volUUID='235b33f4-923c-4cad-91aa-60e36cae15c3', options=None)
>> from=internal, task_id=d90dcc04-6ae8-4ca8-8ede-ca7dee49b6c1 (api:46)
>> 2017-11-21 10:34:16,134-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=d90dcc04-6ae8-4ca8-8ede-ca7dee49b6c1
>> (api:52)
>> 2017-11-21 10:34:17,427-0200 INFO  (jsonrpc/3) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=605ff78e, task_id=43ed860c-719e-4080-9b89-74ef683410ba (api:46)
>> 2017-11-21 10:34:17,428-0200 INFO  (jsonrpc/3) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000501576',
>> 'lastCheck': '1.6', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00316746', 'lastCheck': '1.5', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00385945', 'lastCheck': '0.7',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00840636',
>> 'lastCheck': '1.4', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000503123', 'lastCheck': '1.6', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000342223', 'lastCheck': '6.2',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000397598',
>> 'lastCheck': '0.5', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=605ff78e, task_id=43ed860c-719e-4080-9b89-74ef683410ba (api:52)
>> 2017-11-21 10:34:17,477-0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.05 seconds (__init__:539)
>> 2017-11-21 10:34:18,715-0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)
>> 2017-11-21 10:34:18,755-0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:34:24,164-0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)
>> 2017-11-21 10:34:24,823-0200 INFO  (periodic/342) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=3d7a53d1-917a-40df-8ca9-ef671f6ab5be
>> (api:46)
>> 2017-11-21 10:34:24,824-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000426529',
>> 'lastCheck': '7.0', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00331356', 'lastCheck': '7.1', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00385945', 'lastCheck': '8.1',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00477843',
>> 'lastCheck': '7.1', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000409132', 'lastCheck': '7.0', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000449765', 'lastCheck': '3.6',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000397598',
>> 'lastCheck': '7.9', 'valid': True}} from=internal,
>> task_id=3d7a53d1-917a-40df-8ca9-ef671f6ab5be (api:52)
>> 2017-11-21 10:34:33,526-0200 INFO  (jsonrpc/1) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=3d48c75f, task_id=cbeb394d-1682-464f-a9e1-a2c41434faca (api:46)
>> 2017-11-21 10:34:33,527-0200 INFO  (jsonrpc/1) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000506374',
>> 'lastCheck': '5.7', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00589212', 'lastCheck': '5.8', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00830664', 'lastCheck': '6.8',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00458526',
>> 'lastCheck': '5.8', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000474598', 'lastCheck': '5.7', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000422617', 'lastCheck': '2.3',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000489315',
>> 'lastCheck': '6.6', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=3d48c75f, task_id=cbeb394d-1682-464f-a9e1-a2c41434faca (api:52)
>> 2017-11-21 10:34:33,568-0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.04 seconds (__init__:539)
>> 2017-11-21 10:34:33,776-0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)
>> 2017-11-21 10:34:33,823-0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.01 seconds
>> (__init__:539)
>> 2017-11-21 10:34:35,782-0200 INFO  (monitor/133d2fb) [IOProcessClient]
>> Closing client ioprocess-11889 (__init__:598)
>> 2017-11-21 10:34:35,783-0200 INFO  (monitor/133d2fb) [IOProcessClient]
>> Closing client ioprocess-11888 (__init__:598)
>> 2017-11-21 10:34:39,234-0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:34:39,935-0200 INFO  (periodic/342) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=07f599c7-11c2-4b9a-923e-03d8fc0c8ad2
>> (api:46)
>> 2017-11-21 10:34:39,935-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000465809',
>> 'lastCheck': '2.1', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000473767', 'lastCheck': '2.3', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.0133196', 'lastCheck': '3.2',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.0043482',
>> 'lastCheck': '2.2', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000369036', 'lastCheck': '2.1', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000354937', 'lastCheck': '0.4',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000524776',
>> 'lastCheck': '3.0', 'valid': True}} from=internal,
>> task_id=07f599c7-11c2-4b9a-923e-03d8fc0c8ad2 (api:52)
>> 2017-11-21 10:34:48,856-0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)
>> 2017-11-21 10:34:48,901-0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:34:49,617-0200 INFO  (jsonrpc/0) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=116b15b9, task_id=ed8ead0d-f585-4a1f-b7cc-c06f03678fa6 (api:46)
>> 2017-11-21 10:34:49,618-0200 INFO  (jsonrpc/0) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000454267',
>> 'lastCheck': '1.8', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000485221', 'lastCheck': '1.9', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00717925', 'lastCheck': '2.9',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00925524',
>> 'lastCheck': '1.9', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00040099', 'lastCheck': '1.8', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000347874', 'lastCheck': '0.1',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.00063195',
>> 'lastCheck': '2.7', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=116b15b9, task_id=ed8ead0d-f585-4a1f-b7cc-c06f03678fa6 (api:52)
>> 2017-11-21 10:34:49,657-0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.04 seconds (__init__:539)
>> 2017-11-21 10:34:54,308-0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:34:55,034-0200 INFO  (periodic/341) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=8723cedd-907e-40dc-9289-403b0dcb0408
>> (api:46)
>> 2017-11-21 10:34:55,035-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000454267',
>> 'lastCheck': '7.2', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000485221', 'lastCheck': '7.3', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00717925', 'lastCheck': '8.3',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00925524',
>> 'lastCheck': '7.3', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00040099', 'lastCheck': '7.2', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000347874', 'lastCheck': '3.8',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.00063195',
>> 'lastCheck': '8.1', 'valid': True}} from=internal,
>> task_id=8723cedd-907e-40dc-9289-403b0dcb0408 (api:52)
>> 2017-11-21 10:35:03,918-0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:35:03,942-0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:35:05,232-0200 INFO  (jsonrpc/6) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=5a64ac79, task_id=78bdb2f2-c3ac-48c2-9782-79c3338761df (api:46)
>> 2017-11-21 10:35:05,233-0200 INFO  (jsonrpc/6) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000441852',
>> 'lastCheck': '7.4', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.0104569', 'lastCheck': '7.5', 'valid': True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00748768', 'lastCheck': '8.5',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.0045552',
>> 'lastCheck': '7.5', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000487076', 'lastCheck': '7.4', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000418393', 'lastCheck': '4.0',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.00045539',
>> 'lastCheck': '8.4', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=5a64ac79, task_id=78bdb2f2-c3ac-48c2-9782-79c3338761df (api:52)
>> 2017-11-21 10:35:05,276-0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.05 seconds (__init__:539)
>> 2017-11-21 10:35:05,830-0200 INFO  (monitor/6e71472) [storage.LVM]
>> Refreshing lvs: vg=6e71472a-cb5d-478c-a05f-2dbafbf6ffaa
>> lvs=['metadata'] (lvm:1291)
>> 2017-11-21 10:35:05,831-0200 INFO  (monitor/6e71472) [storage.LVM]
>> Refreshing LVs (vg=6e71472a-cb5d-478c-a05f-2dbafbf6ffaa,
>> lvs=['metadata']) (lvm:1319)
>> 2017-11-21 10:35:05,875-0200 INFO  (monitor/75c38dd) [storage.LVM]
>> Refreshing lvs: vg=75c38dd5-92ad-4b88-93be-4d52489db6e3
>> lvs=['metadata'] (lvm:1291)
>> 2017-11-21 10:35:05,875-0200 INFO  (monitor/75c38dd) [storage.LVM]
>> Refreshing LVs (vg=75c38dd5-92ad-4b88-93be-4d52489db6e3,
>> lvs=['metadata']) (lvm:1319)
>> 2017-11-21 10:35:05,914-0200 INFO  (monitor/aeee636) [storage.LVM]
>> Refreshing lvs: vg=aeee6368-45bb-4a98-937b-587aab3daec3
>> lvs=['metadata'] (lvm:1291)
>> 2017-11-21 10:35:05,915-0200 INFO  (monitor/aeee636) [storage.LVM]
>> Refreshing LVs (vg=aeee6368-45bb-4a98-937b-587aab3daec3,
>> lvs=['metadata']) (lvm:1319)
>> 2017-11-21 10:35:05,983-0200 INFO  (monitor/5f0f31c) [storage.LVM]
>> Refreshing lvs: vg=5f0f31cc-bd1d-4a17-b99f-65e08007ac83
>> lvs=['metadata'] (lvm:1291)
>> 2017-11-21 10:35:05,983-0200 INFO  (monitor/5f0f31c) [storage.LVM]
>> Refreshing LVs (vg=5f0f31cc-bd1d-4a17-b99f-65e08007ac83,
>> lvs=['metadata']) (lvm:1319)
>> 2017-11-21 10:35:06,368-0200 INFO  (monitor/75c38dd) [storage.LVM]
>> Refreshing lvs: vg=75c38dd5-92ad-4b88-93be-4d52489db6e3 lvs=['ids']
>> (lvm:1291)
>> 2017-11-21 10:35:06,368-0200 INFO  (monitor/75c38dd) [storage.LVM]
>> Refreshing LVs (vg=75c38dd5-92ad-4b88-93be-4d52489db6e3, lvs=['ids'])
>> (lvm:1319)
>> 2017-11-21 10:35:06,398-0200 INFO  (monitor/6e71472) [storage.LVM]
>> Refreshing lvs: vg=6e71472a-cb5d-478c-a05f-2dbafbf6ffaa lvs=['ids']
>> (lvm:1291)
>> 2017-11-21 10:35:06,398-0200 INFO  (monitor/6e71472) [storage.LVM]
>> Refreshing LVs (vg=6e71472a-cb5d-478c-a05f-2dbafbf6ffaa, lvs=['ids'])
>> (lvm:1319)
>> 2017-11-21 10:35:06,417-0200 INFO  (monitor/425606b) [storage.LVM]
>> Refreshing lvs: vg=425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> lvs=['metadata'] (lvm:1291)
>> 2017-11-21 10:35:06,418-0200 INFO  (monitor/425606b) [storage.LVM]
>> Refreshing LVs (vg=425606b4-5aa0-4548-8b3f-61a8d0852bf4,
>> lvs=['metadata']) (lvm:1319)
>> 2017-11-21 10:35:06,439-0200 INFO  (monitor/aeee636) [storage.LVM]
>> Refreshing lvs: vg=aeee6368-45bb-4a98-937b-587aab3daec3 lvs=['ids']
>> (lvm:1291)
>> 2017-11-21 10:35:06,440-0200 INFO  (monitor/aeee636) [storage.LVM]
>> Refreshing LVs (vg=aeee6368-45bb-4a98-937b-587aab3daec3, lvs=['ids'])
>> (lvm:1319)
>> 2017-11-21 10:35:06,491-0200 INFO  (monitor/5f0f31c) [storage.LVM]
>> Refreshing lvs: vg=5f0f31cc-bd1d-4a17-b99f-65e08007ac83 lvs=['ids']
>> (lvm:1291)
>> 2017-11-21 10:35:06,492-0200 INFO  (monitor/5f0f31c) [storage.LVM]
>> Refreshing LVs (vg=5f0f31cc-bd1d-4a17-b99f-65e08007ac83, lvs=['ids'])
>> (lvm:1319)
>> 2017-11-21 10:35:06,624-0200 INFO  (monitor/6e71472) [storage.LVM]
>> Refreshing lvs: vg=6e71472a-cb5d-478c-a05f-2dbafbf6ffaa lvs=['leases']
>> (lvm:1291)
>> 2017-11-21 10:35:06,625-0200 INFO  (monitor/6e71472) [storage.LVM]
>> Refreshing LVs (vg=6e71472a-cb5d-478c-a05f-2dbafbf6ffaa,
>> lvs=['leases']) (lvm:1319)
>> 2017-11-21 10:35:06,646-0200 INFO  (monitor/75c38dd) [storage.LVM]
>> Refreshing lvs: vg=75c38dd5-92ad-4b88-93be-4d52489db6e3 lvs=['leases']
>> (lvm:1291)
>> 2017-11-21 10:35:06,646-0200 INFO  (monitor/75c38dd) [storage.LVM]
>> Refreshing LVs (vg=75c38dd5-92ad-4b88-93be-4d52489db6e3,
>> lvs=['leases']) (lvm:1319)
>> 2017-11-21 10:35:06,680-0200 INFO  (monitor/aeee636) [storage.LVM]
>> Refreshing lvs: vg=aeee6368-45bb-4a98-937b-587aab3daec3 lvs=['leases']
>> (lvm:1291)
>> 2017-11-21 10:35:06,680-0200 INFO  (monitor/aeee636) [storage.LVM]
>> Refreshing LVs (vg=aeee6368-45bb-4a98-937b-587aab3daec3,
>> lvs=['leases']) (lvm:1319)
>> 2017-11-21 10:35:06,700-0200 INFO  (monitor/5f0f31c) [storage.LVM]
>> Refreshing lvs: vg=5f0f31cc-bd1d-4a17-b99f-65e08007ac83 lvs=['leases']
>> (lvm:1291)
>> 2017-11-21 10:35:06,701-0200 INFO  (monitor/5f0f31c) [storage.LVM]
>> Refreshing LVs (vg=5f0f31cc-bd1d-4a17-b99f-65e08007ac83,
>> lvs=['leases']) (lvm:1319)
>> 2017-11-21 10:35:06,881-0200 INFO  (monitor/6e71472) [storage.LVM]
>> Refreshing lvs: vg=6e71472a-cb5d-478c-a05f-2dbafbf6ffaa
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master']
>> (lvm:1291)
>> 2017-11-21 10:35:06,882-0200 INFO  (monitor/6e71472) [storage.LVM]
>> Refreshing LVs (vg=6e71472a-cb5d-478c-a05f-2dbafbf6ffaa,
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master'])
>> (lvm:1319)
>> 2017-11-21 10:35:06,923-0200 INFO  (monitor/aeee636) [storage.LVM]
>> Refreshing lvs: vg=aeee6368-45bb-4a98-937b-587aab3daec3
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master']
>> (lvm:1291)
>> 2017-11-21 10:35:06,924-0200 INFO  (monitor/aeee636) [storage.LVM]
>> Refreshing LVs (vg=aeee6368-45bb-4a98-937b-587aab3daec3,
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master'])
>> (lvm:1319)
>> 2017-11-21 10:35:06,946-0200 INFO  (monitor/75c38dd) [storage.LVM]
>> Refreshing lvs: vg=75c38dd5-92ad-4b88-93be-4d52489db6e3
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master']
>> (lvm:1291)
>> 2017-11-21 10:35:06,947-0200 INFO  (monitor/75c38dd) [storage.LVM]
>> Refreshing LVs (vg=75c38dd5-92ad-4b88-93be-4d52489db6e3,
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master'])
>> (lvm:1319)
>> 2017-11-21 10:35:06,973-0200 INFO  (monitor/5f0f31c) [storage.LVM]
>> Refreshing lvs: vg=5f0f31cc-bd1d-4a17-b99f-65e08007ac83
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master']
>> (lvm:1291)
>> 2017-11-21 10:35:06,974-0200 INFO  (monitor/5f0f31c) [storage.LVM]
>> Refreshing LVs (vg=5f0f31cc-bd1d-4a17-b99f-65e08007ac83,
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master'])
>> (lvm:1319)
>> 2017-11-21 10:35:07,000-0200 INFO  (monitor/425606b) [storage.LVM]
>> Refreshing lvs: vg=425606b4-5aa0-4548-8b3f-61a8d0852bf4 lvs=['ids']
>> (lvm:1291)
>> 2017-11-21 10:35:07,001-0200 INFO  (monitor/425606b) [storage.LVM]
>> Refreshing LVs (vg=425606b4-5aa0-4548-8b3f-61a8d0852bf4, lvs=['ids'])
>> (lvm:1319)
>> 2017-11-21 10:35:07,201-0200 INFO  (monitor/425606b) [storage.LVM]
>> Refreshing lvs: vg=425606b4-5aa0-4548-8b3f-61a8d0852bf4 lvs=['leases']
>> (lvm:1291)
>> 2017-11-21 10:35:07,202-0200 INFO  (monitor/425606b) [storage.LVM]
>> Refreshing LVs (vg=425606b4-5aa0-4548-8b3f-61a8d0852bf4,
>> lvs=['leases']) (lvm:1319)
>> 2017-11-21 10:35:07,228-0200 INFO  (monitor/aeee636)
>> [storage.StorageDomain] Resource namespace
01_img_aeee6368-45bb-4a98-937b-587aab3daec3
>> already registered (sd:727)
>> 2017-11-21 10:35:07,228-0200 INFO  (monitor/aeee636)
>> [storage.StorageDomain] Resource namespace
02_vol_aeee6368-45bb-4a98-937b-587aab3daec3
>> already registered (sd:736)
>> 2017-11-21 10:35:07,229-0200 INFO  (monitor/aeee636)
>> [storage.StorageDomain] Resource namespace
03_lvm_aeee6368-45bb-4a98-937b-587aab3daec3
>> already registered (blockSD:989)
>> 2017-11-21 10:35:07,256-0200 INFO  (monitor/5f0f31c)
>> [storage.StorageDomain] Resource namespace
01_img_5f0f31cc-bd1d-4a17-b99f-65e08007ac83
>> already registered (sd:727)
>> 2017-11-21 10:35:07,257-0200 INFO  (monitor/5f0f31c)
>> [storage.StorageDomain] Resource namespace
02_vol_5f0f31cc-bd1d-4a17-b99f-65e08007ac83
>> already registered (sd:736)
>> 2017-11-21 10:35:07,257-0200 INFO  (monitor/5f0f31c)
>> [storage.StorageDomain] Resource namespace
03_lvm_5f0f31cc-bd1d-4a17-b99f-65e08007ac83
>> already registered (blockSD:989)
>> 2017-11-21 10:35:07,286-0200 INFO  (monitor/75c38dd)
>> [storage.StorageDomain] Resource namespace
01_img_75c38dd5-92ad-4b88-93be-4d52489db6e3
>> already registered (sd:727)
>> 2017-11-21 10:35:07,287-0200 INFO  (monitor/75c38dd)
>> [storage.StorageDomain] Resource namespace
02_vol_75c38dd5-92ad-4b88-93be-4d52489db6e3
>> already registered (sd:736)
>> 2017-11-21 10:35:07,288-0200 INFO  (monitor/75c38dd)
>> [storage.StorageDomain] Resource namespace
03_lvm_75c38dd5-92ad-4b88-93be-4d52489db6e3
>> already registered (blockSD:989)
>> 2017-11-21 10:35:07,315-0200 INFO  (monitor/6e71472)
>> [storage.StorageDomain] Resource namespace
01_img_6e71472a-cb5d-478c-a05f-2dbafbf6ffaa
>> already registered (sd:727)
>> 2017-11-21 10:35:07,315-0200 INFO  (monitor/6e71472)
>> [storage.StorageDomain] Resource namespace
02_vol_6e71472a-cb5d-478c-a05f-2dbafbf6ffaa
>> already registered (sd:736)
>> 2017-11-21 10:35:07,316-0200 INFO  (monitor/6e71472)
>> [storage.StorageDomain] Resource namespace
03_lvm_6e71472a-cb5d-478c-a05f-2dbafbf6ffaa
>> already registered (blockSD:989)
>> 2017-11-21 10:35:07,397-0200 INFO  (monitor/425606b) [storage.LVM]
>> Refreshing lvs: vg=425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master']
>> (lvm:1291)
>> 2017-11-21 10:35:07,398-0200 INFO  (monitor/425606b) [storage.LVM]
>> Refreshing LVs (vg=425606b4-5aa0-4548-8b3f-61a8d0852bf4,
>> lvs=['metadata', 'leases', 'ids', 'inbox',
'outbox', 'xleases', 'master'])
>> (lvm:1319)
>> 2017-11-21 10:35:07,611-0200 INFO  (monitor/425606b)
>> [storage.StorageDomain] Resource namespace
01_img_425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> already registered (sd:727)
>> 2017-11-21 10:35:07,612-0200 INFO  (monitor/425606b)
>> [storage.StorageDomain] Resource namespace
02_vol_425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> already registered (sd:736)
>> 2017-11-21 10:35:07,612-0200 INFO  (monitor/425606b)
>> [storage.StorageDomain] Resource namespace
03_lvm_425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> already registered (blockSD:989)
>> 2017-11-21 10:35:09,382-0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:35:10,118-0200 INFO  (periodic/342) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=5ff4e723-4b55-4043-af6c-36b126c1bf47
>> (api:46)
>> 2017-11-21 10:35:10,119-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000463751',
>> 'lastCheck': '2.3', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000490637', 'lastCheck': '2.4', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.000496188', 'lastCheck': '2.4',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000647866',
>> 'lastCheck': '2.4', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000485272', 'lastCheck': '2.3', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000350738', 'lastCheck': '0.6',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000478362',
>> 'lastCheck': '3.1', 'valid': True}} from=internal,
>> task_id=5ff4e723-4b55-4043-af6c-36b126c1bf47 (api:52)
>> 2017-11-21 10:35:16,105-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'aeee6368-45bb-4a98-937b-587aab3daec3',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'046588d2-0d5d-4901-afb4-5902f3e9a7b1',
>> volUUID='80ee1579-fa6c-4c8a-bbe1-3ead1c8b28f9', options=None)
>> from=internal, task_id=812c98fb-55fa-4390-bea9-11ef2343cfaf (api:46)
>> 2017-11-21 10:35:16,106-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '53687091200',
'apparentsize':
>> '53687091200'} from=internal,
task_id=812c98fb-55fa-4390-bea9-11ef2343cfaf
>> (api:52)
>> 2017-11-21 10:35:16,107-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'0f7db06e-7f03-46a5-98c6-264106ad640a',
>> volUUID=u'dc8248bd-fa5d-4627-ad93-d91b6d55090c', options=None)
>> from=internal, task_id=982fa714-367a-4874-8b08-68b2bedfb00d (api:46)
>> 2017-11-21 10:35:16,108-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=982fa714-367a-4874-8b08-68b2bedfb00d
>> (api:52)
>> 2017-11-21 10:35:16,109-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'12eddfe8-e706-4204-95ee-d3ff01bf0db5',
>> volUUID='9b607027-7401-494f-9b48-40d6a3e4abec', options=None)
>> from=internal, task_id=4b59c0d4-d62b-481b-9e9a-d67d147d2dac (api:46)
>> 2017-11-21 10:35:16,110-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=4b59c0d4-d62b-481b-9e9a-d67d147d2dac
>> (api:52)
>> 2017-11-21 10:35:16,111-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'562ca0c9-60b2-419d-aaa2-df6ff10292f6',
>> volUUID='9181c596-93b0-43df-8ab1-b1ee4cb9721b', options=None)
>> from=internal, task_id=916e3f3c-710b-45f5-bd1b-de7a794a3342 (api:46)
>> 2017-11-21 10:35:16,112-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '11811160064',
'apparentsize':
>> '11811160064'} from=internal,
task_id=916e3f3c-710b-45f5-bd1b-de7a794a3342
>> (api:52)
>> 2017-11-21 10:35:16,113-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'bd0c6749-538e-4299-891f-f35da6d8a4a3',
>> volUUID='d95b1638-f829-4264-8667-cd68f26783c0', options=None)
>> from=internal, task_id=c7f40832-eab1-4636-9559-950ec97340b3 (api:46)
>> 2017-11-21 10:35:16,113-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=c7f40832-eab1-4636-9559-950ec97340b3
>> (api:52)
>> 2017-11-21 10:35:16,114-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'ca424d56-f294-48fb-a627-72dac02ec315',
>> volUUID='f241aba7-3ae4-432b-b55c-9ba95ce10e2c', options=None)
>> from=internal, task_id=b4e1683c-ae76-4af5-a2ba-d9aedaba15ec (api:46)
>> 2017-11-21 10:35:16,114-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '35433480192',
'apparentsize':
>> '35433480192'} from=internal,
task_id=b4e1683c-ae76-4af5-a2ba-d9aedaba15ec
>> (api:52)
>> 2017-11-21 10:35:16,115-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'c0327f75-15d3-4aa2-9819-da48694183e2',
>> volUUID='3b846bd2-6698-4cf9-871a-4c867a0fc30f', options=None)
>> from=internal, task_id=1d43b194-c24a-45c1-9a22-7bb1335f532e (api:46)
>> 2017-11-21 10:35:16,116-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '64424509440',
'apparentsize':
>> '64424509440'} from=internal,
task_id=1d43b194-c24a-45c1-9a22-7bb1335f532e
>> (api:52)
>> 2017-11-21 10:35:16,117-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'5c33574c-9b4b-432d-b61e-62bac8c155fd',
>> volUUID='1ddb9ebc-5c6b-4e73-bc2a-3e9983cf9a73', options=None)
>> from=internal, task_id=e16285b2-139b-4563-ae19-f6b3af867526 (api:46)
>> 2017-11-21 10:35:16,118-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=e16285b2-139b-4563-ae19-f6b3af867526
>> (api:52)
>> 2017-11-21 10:35:16,119-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'36bf11d9-5456-4f69-8719-35ed6e0fb305',
>> volUUID='083b0e95-6b45-4904-92be-b1eba0af4289', options=None)
>> from=internal, task_id=0d75f8e1-8e1f-45c1-87db-31e9483ccc7c (api:46)
>> 2017-11-21 10:35:16,120-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '42949672960',
'apparentsize':
>> '42949672960'} from=internal,
task_id=0d75f8e1-8e1f-45c1-87db-31e9483ccc7c
>> (api:52)
>> 2017-11-21 10:35:16,121-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'd68942d0-2ee1-48f5-8f14-580b917e835d',
>> volUUID='5997ab7a-2be3-4790-a9b4-5572da3eeb24', options=None)
>> from=internal, task_id=38ce3a1d-1de6-41fb-99af-44f7cd5f18d4 (api:46)
>> 2017-11-21 10:35:16,122-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=38ce3a1d-1de6-41fb-99af-44f7cd5f18d4
>> (api:52)
>> 2017-11-21 10:35:16,123-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'4fd0ce51-815a-457d-bfd9-1d2c0c2a3f0c',
>> volUUID='e5415881-1bdd-40cc-b2bb-447cfdffd762', options=None)
>> from=internal, task_id=c393da25-6b94-4bda-b5a0-4b8825ec175c (api:46)
>> 2017-11-21 10:35:16,123-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=c393da25-6b94-4bda-b5a0-4b8825ec175c
>> (api:52)
>> 2017-11-21 10:35:16,125-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'ae5b7335-0234-4d39-8b0d-eaa57f3247be',
>> volUUID='b118bb04-c580-49e8-b24d-864f3640fbca', options=None)
>> from=internal, task_id=0702d492-bd44-4954-a09f-de83dc6600f9 (api:46)
>> 2017-11-21 10:35:16,125-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=0702d492-bd44-4954-a09f-de83dc6600f9
>> (api:52)
>> 2017-11-21 10:35:16,126-0200 INFO  (periodic/344) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'50e17b7b-3a86-4797-9c42-8f4562fbf7a5',
>> volUUID='902db022-3300-45d0-9bdc-58c0a2ee7dbc', options=None)
>> from=internal, task_id=9932fcbf-c5e9-4929-9b17-479cff9d64a1 (api:46)
>> 2017-11-21 10:35:16,127-0200 INFO  (periodic/344) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=9932fcbf-c5e9-4929-9b17-479cff9d64a1
>> (api:52)
>> 2017-11-21 10:35:16,128-0200 INFO  (periodic/341) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'a48e6b30-7d29-477e-8b94-a2a4ecd83c98',
>> volUUID='e4a1e27c-4dad-4735-861c-569cba9bc46f', options=None)
>> from=internal, task_id=b4f6d023-31c3-40e6-b977-effd64d83938 (api:46)
>> 2017-11-21 10:35:16,129-0200 INFO  (periodic/341) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '39728447488',
'apparentsize':
>> '39728447488'} from=internal,
task_id=b4f6d023-31c3-40e6-b977-effd64d83938
>> (api:52)
>> 2017-11-21 10:35:16,130-0200 INFO  (periodic/342) [vdsm.api] START
>> getVolumeSize(sdUUID=u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'd8d02bb5-be37-45f2-aaaa-2f28e4fcca25',
>> volUUID='c1c7bb81-6dae-4b1d-a514-4ec5de053994', options=None)
>> from=internal, task_id=eac2b508-c553-48a0-adb9-c8e59dabc6bd (api:46)
>> 2017-11-21 10:35:16,130-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '107374182400',
'apparentsize':
>> '107374182400'} from=internal,
task_id=eac2b508-c553-48a0-adb9-c8e59dabc6bd
>> (api:52)
>> 2017-11-21 10:35:16,131-0200 INFO  (periodic/343) [vdsm.api] START
>> getVolumeSize(sdUUID=u'425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> spUUID=u'59e6568b-02cd-03ad-012a-000000000038',
>> imgUUID=u'f0886b2c-52d4-4f16-9a90-2fdf96d0fb6b',
>> volUUID='235b33f4-923c-4cad-91aa-60e36cae15c3', options=None)
>> from=internal, task_id=eea7dad4-75e2-48ad-b84e-457d59057332 (api:46)
>> 2017-11-21 10:35:16,132-0200 INFO  (periodic/343) [vdsm.api] FINISH
>> getVolumeSize return={'truesize': '10737418240',
'apparentsize':
>> '10737418240'} from=internal,
task_id=eea7dad4-75e2-48ad-b84e-457d59057332
>> (api:52)
>> 2017-11-21 10:35:18,968-0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:35:18,992-0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:35:20,334-0200 INFO  (jsonrpc/0) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=d08b563, task_id=18b273c7-bd84-4c07-9c9a-1dd57ad06f75 (api:46)
>> 2017-11-21 10:35:20,334-0200 INFO  (jsonrpc/0) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000446587',
>> 'lastCheck': '2.5', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00675086', 'lastCheck': '2.7', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00947756', 'lastCheck': '2.6',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00622928',
>> 'lastCheck': '2.6', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000379158', 'lastCheck': '2.5', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000417515', 'lastCheck': '0.8',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000524652',
>> 'lastCheck': '3.4', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=d08b563, task_id=18b273c7-bd84-4c07-9c9a-1dd57ad06f75 (api:52)
>> 2017-11-21 10:35:20,377-0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.05 seconds (__init__:539)
>> 2017-11-21 10:35:24,451-0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:35:25,220-0200 INFO  (periodic/342) [vdsm.api] START
>> repoStats(options=None) from=internal,
task_id=2c55d8e7-8b6a-4056-8855-e142ad434837
>> (api:46)
>> 2017-11-21 10:35:25,221-0200 INFO  (periodic/342) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000446587',
>> 'lastCheck': '7.4', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00675086', 'lastCheck': '7.5', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.00947756', 'lastCheck': '7.5',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.00622928',
>> 'lastCheck': '7.5', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000379158', 'lastCheck': '7.4', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000417515', 'lastCheck': '4.0',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000524652',
>> 'lastCheck': '8.3', 'valid': True}} from=internal,
>> task_id=2c55d8e7-8b6a-4056-8855-e142ad434837 (api:52)
>> 2017-11-21 10:35:34,023-0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)
>> 2017-11-21 10:35:34,075-0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer]
>> RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds
>> (__init__:539)
>> 2017-11-21 10:35:35,424-0200 INFO  (jsonrpc/6) [vdsm.api] START
>> repoStats(options=None) from=::ffff:192.168.254.80,50314,
>> flow_id=2d6c655b, task_id=d3853c42-2d16-408a-9411-d2a84fcad926 (api:46)
>> 2017-11-21 10:35:35,425-0200 INFO  (jsonrpc/6) [vdsm.api] FINISH
>> repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000436053',
>> 'lastCheck': '7.6', 'valid': True},
u'aeee6368-45bb-4a98-937b-587aab3daec3':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.00633629', 'lastCheck': '7.7', 'valid':
True},
>> u'425606b4-5aa0-4548-8b3f-61a8d0852bf4': {'code': 0,
'actual': True,
>> 'version': 4, 'acquired': True, 'delay':
'0.0142374', 'lastCheck': '7.7',
>> 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e08007ac83':
{'code': 0,
>> 'actual': True, 'version': 4, 'acquired': True,
'delay': '0.000593453',
>> 'lastCheck': '7.7', 'valid': True},
u'6e71472a-cb5d-478c-a05f-2dbafbf6ffaa':
>> {'code': 0, 'actual': True, 'version': 4,
'acquired': True, 'delay':
>> '0.000385028', 'lastCheck': '7.6', 'valid':
True},
>> u'0048460a-9fc0-45c8-851d-86b17f872827': {'code': 0,
'actual': True,
>> 'version': 0, 'acquired': True, 'delay':
'0.000419577', 'lastCheck': '4.2',
>> 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e72f3f49d':
{'code': 0,
>> 'actual': True, 'version': 0, 'acquired': True,
'delay': '0.000364547',
>> 'lastCheck': '8.6', 'valid': True}}
from=::ffff:192.168.254.80,50314,
>> flow_id=2d6c655b, task_id=d3853c42-2d16-408a-9411-d2a84fcad926 (api:52)
>> 2017-11-21 10:35:35,486-0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer]
>> RPC call Host.getStats succeeded in 0.07 seconds (__init__:539)
>>
>>
>> ----
>>
>> engine.log
>>
>> 2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription',
>> parameters:
>> 2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
>> 2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> 2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ imageGroupGUID=808b9847-c42c-40d8-959d-5faff30cbaff
>> 2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af22-d210fabfc8ce
>> 2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ description={"Updated":false,"Last
Updated":"Fri Nov 17
>> 18:28:47 BRST 2017","Storage
Domains":[{"uuid":"425606b4-5a
>> a0-4548-8b3f-61a8d0852bf4"}],"Disk
Description":"OVF_STORE"}
>> 2017-11-21 10:29:16,693-02 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
>> (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b6378408a9d] Ending
>> command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand'
>> with failure.
>> 2017-11-21 10:29:16,696-02 INFO 
[org.ovirt.engine.core.utils.transaction.TransactionSupport]
>> (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>> transaction rolled back
>> 2017-11-21 10:29:16,708-02 ERROR [org.ovirt.engine.core.dal.dbb
>> roker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler6)
>> [70cc2ffa-2414-4a00-9e24-6b6378408a9d] EVENT_ID:
>> USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Correlation ID:
>> 70cc2ffa-2414-4a00-9e24-6b6378408a9d, Job ID:
>> ec197072-7c38-42b6-9aef-99635d4ee135, Call Stack: null, Custom ID:
>> null, Custom Event ID: -1, Message: Failed to delete snapshot
'<UNKNOWN>'
>> for VM 'proxy03'.
>> 2017-11-21 10:29:16,709-02 ERROR
[org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller]
>> (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b6378408a9d] Failed
>> invoking callback end method 'onFailed' for command
>> 'a84519fe-6b23-4084-84a2-b7964cbcde26' with exception 'null',
the
>> callback is marked for end method retries
>> 2017-11-21 10:29:16,838-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] FINISH, SetVolumeDescriptionVDSCommand, log id: 2bfd570
>> 2017-11-21 10:29:16,862-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand] (DefaultQuartzScheduler2) [58f0924f]
>> Lock Acquired to object 'EngineLock:{exclusiveLocks='',
>> sharedLocks='[5386322c-bf91-4bf5-8507-128f7473aa8d=VDS_EXECUTION]'}'
>> 2017-11-21 10:29:16,897-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand] (DefaultQuartzScheduler2) [58f0924f]
>> Running command: UploadStreamCommand internal: true. Entities affected :
>> ID: 425606b4-5aa0-4548-8b3f-61a8d0852bf4 Type: Storage
>> 2017-11-21 10:29:16,897-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] START, UploadStreamVDSCommand(HostName = host01-dc1,
>> UploadStreamVDSCommandParameters:{runAsync='true',
>> hostId='5386322c-bf91-4bf5-8507-128f7473aa8d'}), log id: 78526132
>> 2017-11-21 10:29:16,897-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] -- executeVdsBrokerCommand, parameters:
>> 2017-11-21 10:29:16,897-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
>> 2017-11-21 10:29:16,898-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> 2017-11-21 10:29:16,898-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ imageGUID=808b9847-c42c-40d8-959d-5faff30cbaff
>> 2017-11-21 10:29:16,898-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af22-d210fabfc8ce
>> 2017-11-21 10:29:16,898-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ size=235520
>> 2017-11-21 10:29:20,138-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] FINISH, UploadStreamVDSCommand, log id: 78526132
>> 2017-11-21 10:29:20,163-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (DefaultQuartzScheduler2) [58f0924f] CommandAsyncTask::Adding
>> CommandMultiAsyncTasks object for command 'd73dc4e7-e0b8-4a19-a672-5ef67
>> 8f64a08'
>> 2017-11-21 10:29:20,163-02 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
>> (DefaultQuartzScheduler2) [58f0924f] CommandMultiAsyncTasks::attachTask:
>> Attaching task '5fe5e889-1065-4e77-834b-71620e2f23e5' to command
>> 'd73dc4e7-e0b8-4a19-a672-5ef678f64a08'.
>> 2017-11-21 10:29:20,186-02 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
>> (DefaultQuartzScheduler2) [58f0924f] Adding task
>> '5fe5e889-1065-4e77-834b-71620e2f23e5' (Parent Command
'UploadStream',
>> Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters'), polling hasn't started yet..
>> 2017-11-21 10:29:20,197-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (DefaultQuartzScheduler2) [58f0924f] BaseAsyncTask::startPollingTask:
>> Starting to poll task '5fe5e889-1065-4e77-834b-71620e2f23e5'.
>> 2017-11-21 10:29:20,205-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand] (DefaultQuartzScheduler2) [58f0924f]
>> Lock freed to object 'EngineLock:{exclusiveLocks='',
>> sharedLocks='[5386322c-bf91-4bf5-8507-128f7473aa8d=VDS_EXECUTION]'}'
>> 2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] START, SetVolumeDescriptionVDSCommand(
>> SetVolumeDescriptionVDSCommandParameters:{runAsync='true',
>> storagePoolId='59e6568b-02cd-03ad-012a-000000000038',
>> ignoreFailoverLimit='false',
storageDomainId='425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> imageGroupId='808b9847-c42c-40d8-959d-5faff30cbaff',
>> imageId='f9d2654b-9f27-4e60-af22-d210fabfc8ce'}), log id: 111fc33a
>> 2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription',
>> parameters:
>> 2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
>> 2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> 2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ imageGroupGUID=808b9847-c42c-40d8-959d-5faff30cbaff
>> 2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af22-d210fabfc8ce
>> 2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++
description={"Updated":true,"Size":235520,"Last
>> Updated":"Tue Nov 21 10:29:15 BRST 2017","Storage
>>
Domains":[{"uuid":"425606b4-5aa0-4548-8b3f-61a8d0852bf4"}],"Disk
>> Description":"OVF_STORE"}
>> 2017-11-21 10:29:20,566-02 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
>> (DefaultQuartzScheduler7) [5dee72f] Polling and updating Async Tasks: 1
>> tasks, 1 tasks to poll now
>> 2017-11-21 10:29:21,540-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] FINISH, SetVolumeDescriptionVDSCommand, log id: 111fc33a
>> 2017-11-21 10:29:21,545-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] START, SetVolumeDescriptionVDSCommand(
>> SetVolumeDescriptionVDSCommandParameters:{runAsync='true',
>> storagePoolId='59e6568b-02cd-03ad-012a-000000000038',
>> ignoreFailoverLimit='false',
storageDomainId='425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> imageGroupId='5919ccc4-b9ad-4213-810b-4f8df08efdf5',
>> imageId='85a0eb12-2d70-4ae1-8c11-20ef30bbf839'}), log id: 7cc59230
>> 2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (DefaultQuartzScheduler7) [5dee72f] SPMAsyncTask::PollTask: Polling task
>> '5fe5e889-1065-4e77-834b-71620e2f23e5' (Parent Command
'UploadStream',
>> Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters') returned status 'finished', result
>> 'success'.
>> 2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription',
>> parameters:
>> 2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
>> 2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> 2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (DefaultQuartzScheduler7) [5dee72f] BaseAsyncTask::onTaskEndSuccess:
>> Task '5fe5e889-1065-4e77-834b-71620e2f23e5' (Parent Command
>> 'UploadStream', Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters') ended successfully.
>> 2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ imageGroupGUID=5919ccc4-b9ad-4213-810b-4f8df08efdf5
>> 2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c11-20ef30bbf839
>> 2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ description={"Updated":false,"Last
Updated":"Fri Nov 17
>> 18:28:47 BRST 2017","Storage
Domains":[{"uuid":"425606b4-5a
>> a0-4548-8b3f-61a8d0852bf4"}],"Disk
Description":"OVF_STORE"}
>> 2017-11-21 10:29:22,498-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (DefaultQuartzScheduler7) [5dee72f] CommandAsyncTask::endActionIfNecessary:
>> All tasks of command 'd73dc4e7-e0b8-4a19-a672-5ef678f64a08' has ended
>> -> executing 'endAction'
>> 2017-11-21 10:29:22,498-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (DefaultQuartzScheduler7) [5dee72f] CommandAsyncTask::endAction: Ending
>> action for '1' tasks (command ID:
'd73dc4e7-e0b8-4a19-a672-5ef678f64a08'):
>> calling endAction '.
>> 2017-11-21 10:29:22,498-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-2) [5dee72f]
>> CommandAsyncTask::endCommandAction [within thread] context: Attempting
>> to endAction 'UploadStream',
>> 2017-11-21 10:29:22,505-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand] (org.ovirt.thread.pool-6-thread-2)
>> [58f0924f] Ending command 'org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand' successfully.
>> 2017-11-21 10:29:22,511-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-2) [58f0924f]
>> CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
>> action type 'UploadStream' completed, handling the result.
>> 2017-11-21 10:29:22,511-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-2) [58f0924f]
>> CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
>> action type 'UploadStream' succeeded, clearing tasks.
>> 2017-11-21 10:29:22,511-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (org.ovirt.thread.pool-6-thread-2) [58f0924f]
>> SPMAsyncTask::ClearAsyncTask: Attempting to clear task
>> '5fe5e889-1065-4e77-834b-71620e2f23e5'
>> 2017-11-21 10:29:22,512-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-2)
>> [58f0924f] START, SPMClearTaskVDSCommand(
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true',
>> storagePoolId='59e6568b-02cd-03ad-012a-000000000038',
>> ignoreFailoverLimit='false',
taskId='5fe5e889-1065-4e77-834b-71620e2f23e5'}),
>> log id: 4a85156f
>> 2017-11-21 10:29:23,873-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] FINISH, SetVolumeDescriptionVDSCommand, log id: 7cc59230
>> 2017-11-21 10:29:23,874-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-2)
>> [58f0924f] START, HSMClearTaskVDSCommand(HostName = host01-dc1,
>> HSMTaskGuidBaseVDSCommandParameters:{runAsync='true',
>> hostId='5386322c-bf91-4bf5-8507-128f7473aa8d',
>> taskId='5fe5e889-1065-4e77-834b-71620e2f23e5'}), log id: 7920c7e6
>> 2017-11-21 10:29:23,889-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand] (DefaultQuartzScheduler2) [58f0924f]
>> Lock Acquired to object 'EngineLock:{exclusiveLocks='',
>> sharedLocks='[5386322c-bf91-4bf5-8507-128f7473aa8d=VDS_EXECUTION]'}'
>> 2017-11-21 10:29:23,915-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand] (DefaultQuartzScheduler2) [58f0924f]
>> Running command: UploadStreamCommand internal: true. Entities affected :
>> ID: 425606b4-5aa0-4548-8b3f-61a8d0852bf4 Type: Storage
>> 2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] START, UploadStreamVDSCommand(HostName = host01-dc1,
>> UploadStreamVDSCommandParameters:{runAsync='true',
>> hostId='5386322c-bf91-4bf5-8507-128f7473aa8d'}), log id: 2fc55e39
>> 2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] -- executeVdsBrokerCommand, parameters:
>> 2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
>> 2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> 2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ imageGUID=5919ccc4-b9ad-4213-810b-4f8df08efdf5
>> 2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c11-20ef30bbf839
>> 2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ size=235520
>> 2017-11-21 10:29:24,856-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-2)
>> [58f0924f] FINISH, HSMClearTaskVDSCommand, log id: 7920c7e6
>> 2017-11-21 10:29:24,856-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-2)
>> [58f0924f] FINISH, SPMClearTaskVDSCommand, log id: 4a85156f
>> 2017-11-21 10:29:24,861-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (org.ovirt.thread.pool-6-thread-2) [58f0924f]
>> BaseAsyncTask::removeTaskFromDB: Removed task
>> '5fe5e889-1065-4e77-834b-71620e2f23e5' from DataBase
>> 2017-11-21 10:29:24,861-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-2) [58f0924f]
>> CommandAsyncTask::HandleEndActionResult [within thread]: Removing
>> CommandMultiAsyncTasks object for entity 'd73dc4e7-e0b8-4a19-a672-5ef67
>> 8f64a08'
>> 2017-11-21 10:29:26,721-02 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
>> (DefaultQuartzScheduler8) [70cc2ffa-2414-4a00-9e24-6b6378408a9d] Ending
>> command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand'
>> with failure.
>> 2017-11-21 10:29:26,725-02 INFO 
[org.ovirt.engine.core.utils.transaction.TransactionSupport]
>> (DefaultQuartzScheduler8) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>> transaction rolled back
>> 2017-11-21 10:29:26,737-02 ERROR [org.ovirt.engine.core.dal.dbb
>> roker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler8)
>> [70cc2ffa-2414-4a00-9e24-6b6378408a9d] EVENT_ID:
>> USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Correlation ID:
>> 70cc2ffa-2414-4a00-9e24-6b6378408a9d, Job ID:
>> ec197072-7c38-42b6-9aef-99635d4ee135, Call Stack: null, Custom ID:
>> null, Custom Event ID: -1, Message: Failed to delete snapshot
'<UNKNOWN>'
>> for VM 'proxy03'.
>> 2017-11-21 10:29:26,738-02 ERROR
[org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller]
>> (DefaultQuartzScheduler8) [70cc2ffa-2414-4a00-9e24-6b6378408a9d] Failed
>> invoking callback end method 'onFailed' for command
>> 'a84519fe-6b23-4084-84a2-b7964cbcde26' with exception 'null',
the
>> callback is marked for end method retries
>> 2017-11-21 10:29:26,898-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] FINISH, UploadStreamVDSCommand, log id: 2fc55e39
>> 2017-11-21 10:29:26,922-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (DefaultQuartzScheduler2) [58f0924f] CommandAsyncTask::Adding
>> CommandMultiAsyncTasks object for command '874fc31b-f30d-44da-9c85-083fc
>> 4a5c1b8'
>> 2017-11-21 10:29:26,922-02 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
>> (DefaultQuartzScheduler2) [58f0924f] CommandMultiAsyncTasks::attachTask:
>> Attaching task 'e9424be5-5fa9-45fd-9d1d-db952733670c' to command
>> '874fc31b-f30d-44da-9c85-083fc4a5c1b8'.
>> 2017-11-21 10:29:26,945-02 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
>> (DefaultQuartzScheduler2) [58f0924f] Adding task
>> 'e9424be5-5fa9-45fd-9d1d-db952733670c' (Parent Command
'UploadStream',
>> Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters'), polling hasn't started yet..
>> 2017-11-21 10:29:26,956-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (DefaultQuartzScheduler2) [58f0924f] BaseAsyncTask::startPollingTask:
>> Starting to poll task 'e9424be5-5fa9-45fd-9d1d-db952733670c'.
>> 2017-11-21 10:29:26,964-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand] (DefaultQuartzScheduler2) [58f0924f]
>> Lock freed to object 'EngineLock:{exclusiveLocks='',
>> sharedLocks='[5386322c-bf91-4bf5-8507-128f7473aa8d=VDS_EXECUTION]'}'
>> 2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] START, SetVolumeDescriptionVDSCommand(
>> SetVolumeDescriptionVDSCommandParameters:{runAsync='true',
>> storagePoolId='59e6568b-02cd-03ad-012a-000000000038',
>> ignoreFailoverLimit='false',
storageDomainId='425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> imageGroupId='5919ccc4-b9ad-4213-810b-4f8df08efdf5',
>> imageId='85a0eb12-2d70-4ae1-8c11-20ef30bbf839'}), log id: 3e073336
>> 2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription',
>> parameters:
>> 2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
>> 2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
>> 2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ imageGroupGUID=5919ccc4-b9ad-4213-810b-4f8df08efdf5
>> 2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c11-20ef30bbf839
>> 2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] ++
description={"Updated":true,"Size":235520,"Last
>> Updated":"Tue Nov 21 10:29:15 BRST 2017","Storage
>>
Domains":[{"uuid":"425606b4-5aa0-4548-8b3f-61a8d0852bf4"}],"Disk
>> Description":"OVF_STORE"}
>> 2017-11-21 10:29:28,223-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2)
>> [58f0924f] FINISH, SetVolumeDescriptionVDSCommand, log id: 3e073336
>> 2017-11-21 10:29:28,237-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.ProcessOvfUpdateForStorageDomainCommand]
>> (DefaultQuartzScheduler2) [58f0924f] Lock freed to object
>>
'EngineLock:{exclusiveLocks='[425606b4-5aa0-4548-8b3f-61a8d0852bf4=STORAGE]',
>> sharedLocks='[59e6568b-02cd-03ad-012a-000000000038=OVF_UPDATE]'}'
>> 2017-11-21 10:29:29,784-02 INFO  [org.ovirt.engine.core.bll.Ser
>> ialChildCommandsExecutionCallback] (DefaultQuartzScheduler9) [58f0924f]
>> Command 'ProcessOvfUpdateForStorageDomain' (id:
>> '10a201e9-d1b4-45f0-99a0-74d6114ac8b5') waiting on child command id:
>> '874fc31b-f30d-44da-9c85-083fc4a5c1b8' type:'UploadStream' to
complete
>> 2017-11-21 10:29:31,780-02 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (default task-200) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde] Lock Acquired
>> to object
'EngineLock:{exclusiveLocks='[5cb5e5c4-253b-4ab5-a93f-3661e6ab54ac=VM]',
>> sharedLocks=''}'
>> 2017-11-21 10:29:31,868-02 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (org.ovirt.thread.pool-6-thread-27) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde]
>> Running command: RemoveVmCommand internal: false. Entities affected :  ID:
>> 5cb5e5c4-253b-4ab5-a93f-3661e6ab54ac Type: VMAction group DELETE_VM
>> with role type USER
>> 2017-11-21 10:29:31,869-02 INFO 
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand]
>> (org.ovirt.thread.pool-6-thread-27) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde]
>> START, SetVmStatusVDSCommand(
SetVmStatusVDSCommandParameters:{runAsync='true',
>> vmId='5cb5e5c4-253b-4ab5-a93f-3661e6ab54ac',
status='ImageLocked',
>> exitStatus='Normal'}), log id: 10a18186
>> 2017-11-21 10:29:31,872-02 INFO 
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand]
>> (org.ovirt.thread.pool-6-thread-27) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde]
>> FINISH, SetVmStatusVDSCommand, log id: 10a18186
>> 2017-11-21 10:29:31,875-02 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (org.ovirt.thread.pool-6-thread-27) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde]
>> Lock freed to object 'EngineLock:{exclusiveLocks='[
>> 5cb5e5c4-253b-4ab5-a93f-3661e6ab54ac=VM]', sharedLocks=''}'
>> 2017-11-21 10:29:31,902-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.disk.image.RemoveAllVmImagesCommand] (org.ovirt.thread.pool-6-thread-27)
>> [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde] Running command:
>> RemoveAllVmImagesCommand internal: true. Entities affected :  ID:
>> 5cb5e5c4-253b-4ab5-a93f-3661e6ab54ac Type: VM
>> 2017-11-21 10:29:31,930-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.disk.image.RemoveImageCommand] (org.ovirt.thread.pool-6-thread-27)
>> [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde] Running command:
>> RemoveImageCommand internal: true. Entities affected :  ID:
>> 00000000-0000-0000-0000-000000000000 Type: Storage
>> 2017-11-21 10:29:32,002-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-6-thread-27)
>> [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde] START,
>> DeleteImageGroupVDSCommand(
DeleteImageGroupVDSCommandParameters:{runAsync='true',
>> storagePoolId='59e6568b-02cd-03ad-012a-000000000038',
>> ignoreFailoverLimit='false',
storageDomainId='425606b4-5aa0-4548-8b3f-61a8d0852bf4',
>> imageGroupId='fb163891-3a74-4abc-a576-444675d447e4',
postZeros='false',
>> discard='false', forceDelete='false'}), log id: 4b43a62a
>> 2017-11-21 10:29:32,498-02 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
>> (DefaultQuartzScheduler1) [6523c570] Polling and updating Async Tasks: 2
>> tasks, 1 tasks to poll now
>> 2017-11-21 10:29:33,587-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-6-thread-27)
>> [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde] FINISH,
>> DeleteImageGroupVDSCommand, log id: 4b43a62a
>> 2017-11-21 10:29:33,594-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-27) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde]
>> CommandAsyncTask::Adding CommandMultiAsyncTasks object for command
>> '785b30c0-a425-4ad0-9a68-9740d2c9dc1b'
>> 2017-11-21 10:29:33,594-02 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
>> (org.ovirt.thread.pool-6-thread-27) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde]
>> CommandMultiAsyncTasks::attachTask: Attaching task
>> 'f585094e-d892-4840-af64-663571cfd35f' to command
>> '785b30c0-a425-4ad0-9a68-9740d2c9dc1b'.
>> 2017-11-21 10:29:33,633-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (DefaultQuartzScheduler1) [6523c570] SPMAsyncTask::PollTask: Polling task
>> 'e9424be5-5fa9-45fd-9d1d-db952733670c' (Parent Command
'UploadStream',
>> Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters') returned status 'finished', result
>> 'success'.
>> 2017-11-21 10:29:33,633-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (DefaultQuartzScheduler1) [6523c570] BaseAsyncTask::onTaskEndSuccess:
>> Task 'e9424be5-5fa9-45fd-9d1d-db952733670c' (Parent Command
>> 'UploadStream', Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters') ended successfully.
>> 2017-11-21 10:29:33,634-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (DefaultQuartzScheduler1) [6523c570] CommandAsyncTask::endActionIfNecessary:
>> All tasks of command '874fc31b-f30d-44da-9c85-083fc4a5c1b8' has ended
>> -> executing 'endAction'
>> 2017-11-21 10:29:33,634-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (DefaultQuartzScheduler1) [6523c570] CommandAsyncTask::endAction: Ending
>> action for '1' tasks (command ID:
'874fc31b-f30d-44da-9c85-083fc4a5c1b8'):
>> calling endAction '.
>> 2017-11-21 10:29:33,634-02 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
>> (org.ovirt.thread.pool-6-thread-27) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde]
>> Adding task 'f585094e-d892-4840-af64-663571cfd35f' (Parent Command
>> 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters'), polling hasn't started yet..
>> 2017-11-21 10:29:33,634-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-34) [6523c570]
>> CommandAsyncTask::endCommandAction [within thread] context: Attempting
>> to endAction 'UploadStream',
>> 2017-11-21 10:29:33,643-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand] (org.ovirt.thread.pool-6-thread-34)
>> [58f0924f] Ending command 'org.ovirt.engine.core.bll.sto
>> rage.ovfstore.UploadStreamCommand' successfully.
>> 2017-11-21 10:29:33,654-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-34) [58f0924f]
>> CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
>> action type 'UploadStream' completed, handling the result.
>> 2017-11-21 10:29:33,654-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-34) [58f0924f]
>> CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
>> action type 'UploadStream' succeeded, clearing tasks.
>> 2017-11-21 10:29:33,654-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (org.ovirt.thread.pool-6-thread-34) [58f0924f]
>> SPMAsyncTask::ClearAsyncTask: Attempting to clear task
>> 'e9424be5-5fa9-45fd-9d1d-db952733670c'
>> 2017-11-21 10:29:33,655-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-34)
>> [58f0924f] START, SPMClearTaskVDSCommand(
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true',
>> storagePoolId='59e6568b-02cd-03ad-012a-000000000038',
>> ignoreFailoverLimit='false',
taskId='e9424be5-5fa9-45fd-9d1d-db952733670c'}),
>> log id: 76cd0e96
>> 2017-11-21 10:29:33,656-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-34)
>> [58f0924f] START, HSMClearTaskVDSCommand(HostName = host01-dc1,
>> HSMTaskGuidBaseVDSCommandParameters:{runAsync='true',
>> hostId='5386322c-bf91-4bf5-8507-128f7473aa8d',
>> taskId='e9424be5-5fa9-45fd-9d1d-db952733670c'}), log id: 6bb3135e
>> 2017-11-21 10:29:33,803-02 INFO  [org.ovirt.engine.core.dal.dbb
>> roker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-27)
>> [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde] EVENT_ID:
>> USER_REMOVE_VM_FINISHED(113), Correlation ID:
6454d8f7-93e6-47ae-ba9b-a5a075c1cfde,
>> Job ID: 49662b64-2b05-4b32-acd7-412db971e99b, Call Stack: null, Custom
>> ID: null, Custom Event ID: -1, Message: VM unifi-controller was
>> successfully removed.
>> 2017-11-21 10:29:33,804-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (org.ovirt.thread.pool-6-thread-27) [6454d8f7-93e6-47ae-ba9b-a5a075c1cfde]
>> BaseAsyncTask::startPollingTask: Starting to poll task
>> 'f585094e-d892-4840-af64-663571cfd35f'.
>> 2017-11-21 10:29:33,825-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-34)
>> [58f0924f] FINISH, HSMClearTaskVDSCommand, log id: 6bb3135e
>> 2017-11-21 10:29:33,825-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-34)
>> [58f0924f] FINISH, SPMClearTaskVDSCommand, log id: 76cd0e96
>> 2017-11-21 10:29:33,830-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (org.ovirt.thread.pool-6-thread-34) [58f0924f]
>> BaseAsyncTask::removeTaskFromDB: Removed task
>> 'e9424be5-5fa9-45fd-9d1d-db952733670c' from DataBase
>> 2017-11-21 10:29:33,830-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-34) [58f0924f]
>> CommandAsyncTask::HandleEndActionResult [within thread]: Removing
>> CommandMultiAsyncTasks object for entity '874fc31b-f30d-44da-9c85-083fc
>> 4a5c1b8'
>> 2017-11-21 10:29:36,879-02 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
>> (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>> Ending command
'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand'
>> with failure.
>> 2017-11-21 10:29:36,883-02 INFO 
[org.ovirt.engine.core.utils.transaction.TransactionSupport]
>> (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>> transaction rolled back
>> 2017-11-21 10:29:36,895-02 ERROR [org.ovirt.engine.core.dal.dbb
>> roker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler10)
>> [70cc2ffa-2414-4a00-9e24-6b6378408a9d] EVENT_ID:
>> USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Correlation ID:
>> 70cc2ffa-2414-4a00-9e24-6b6378408a9d, Job ID:
>> ec197072-7c38-42b6-9aef-99635d4ee135, Call Stack: null, Custom ID:
>> null, Custom Event ID: -1, Message: Failed to delete snapshot
'<UNKNOWN>'
>> for VM 'proxy03'.
>> 2017-11-21 10:29:36,895-02 ERROR
[org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller]
>> (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>> Failed invoking callback end method 'onFailed' for command
>> 'a84519fe-6b23-4084-84a2-b7964cbcde26' with exception 'null',
the
>> callback is marked for end method retries
>> 2017-11-21 10:29:39,937-02 INFO  [org.ovirt.engine.core.bll.Ser
>> ialChildCommandsExecutionCallback] (DefaultQuartzScheduler8) [58f0924f]
>> Command 'ProcessOvfUpdateForStorageDomain' id:
>> '10a201e9-d1b4-45f0-99a0-74d6114ac8b5' child commands
>> '[d73dc4e7-e0b8-4a19-a672-5ef678f64a08,
874fc31b-f30d-44da-9c85-083fc4a5c1b8]'
>> executions were completed, status 'SUCCEEDED'
>> 2017-11-21 10:29:40,974-02 INFO  [org.ovirt.engine.core.bll.sto
>> rage.ovfstore.ProcessOvfUpdateForStorageDomainCommand]
>> (DefaultQuartzScheduler5) [58f0924f] Ending command
>>
'org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStorageDomainCommand'
>> successfully.
>> 2017-11-21 10:29:43,634-02 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
>> (DefaultQuartzScheduler9) [7b755e5d] Polling and updating Async Tasks: 3
>> tasks, 1 tasks to poll now
>> 2017-11-21 10:29:45,920-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (DefaultQuartzScheduler9) [7b755e5d] SPMAsyncTask::PollTask: Polling task
>> 'f585094e-d892-4840-af64-663571cfd35f' (Parent Command
'RemoveVm',
>> Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters') returned status 'finished', result
>> 'success'.
>> 2017-11-21 10:29:45,925-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (DefaultQuartzScheduler9) [7b755e5d] BaseAsyncTask::onTaskEndSuccess:
>> Task 'f585094e-d892-4840-af64-663571cfd35f' (Parent Command
'RemoveVm',
>> Parameters Type 'org.ovirt.engine.core.common.
>> asynctasks.AsyncTaskParameters') ended successfully.
>> 2017-11-21 10:29:45,928-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (DefaultQuartzScheduler9) [7b755e5d] CommandAsyncTask::endActionIfNecessary:
>> All tasks of command '785b30c0-a425-4ad0-9a68-9740d2c9dc1b' has ended
>> -> executing 'endAction'
>> 2017-11-21 10:29:45,928-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (DefaultQuartzScheduler9) [7b755e5d] CommandAsyncTask::endAction: Ending
>> action for '1' tasks (command ID:
'785b30c0-a425-4ad0-9a68-9740d2c9dc1b'):
>> calling endAction '.
>> 2017-11-21 10:29:45,928-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-32) [7b755e5d]
>> CommandAsyncTask::endCommandAction [within thread] context: Attempting
>> to endAction 'RemoveVm',
>> 2017-11-21 10:29:45,941-02 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (org.ovirt.thread.pool-6-thread-32) [7b755e5d] Ending command
>> 'org.ovirt.engine.core.bll.RemoveVmCommand' successfully.
>> 2017-11-21 10:29:45,946-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-32) [7b755e5d]
>> CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
>> action type 'RemoveVm' completed, handling the result.
>> 2017-11-21 10:29:45,946-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-32) [7b755e5d]
>> CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
>> action type 'RemoveVm' succeeded, clearing tasks.
>> 2017-11-21 10:29:45,946-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (org.ovirt.thread.pool-6-thread-32) [7b755e5d]
>> SPMAsyncTask::ClearAsyncTask: Attempting to clear task
>> 'f585094e-d892-4840-af64-663571cfd35f'
>> 2017-11-21 10:29:45,947-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-32)
>> [7b755e5d] START, SPMClearTaskVDSCommand(
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true',
>> storagePoolId='59e6568b-02cd-03ad-012a-000000000038',
>> ignoreFailoverLimit='false',
taskId='f585094e-d892-4840-af64-663571cfd35f'}),
>> log id: 575b7d94
>> 2017-11-21 10:29:45,947-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-32)
>> [7b755e5d] START, HSMClearTaskVDSCommand(HostName = host01-dc1,
>> HSMTaskGuidBaseVDSCommandParameters:{runAsync='true',
>> hostId='5386322c-bf91-4bf5-8507-128f7473aa8d',
>> taskId='f585094e-d892-4840-af64-663571cfd35f'}), log id: 6164bf23
>> 2017-11-21 10:29:46,288-02 INFO 
[org.ovirt.engine.core.bll.aaa.SessionDataContainer]
>> (DefaultQuartzScheduler1) [6fd44373] Not removing session
>> 'N8YCGRnduzKPm0RIBJIstocZIdkPAukaKCYDXwWncjWW/NhWw7X1/pSq07h
>> ifciMHWlan+xMcaQPka3gyX9tXQ==', session has running commands for user
>> 'admin@internal-authz'.
>> 2017-11-21 10:29:46,974-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-32)
>> [7b755e5d] FINISH, HSMClearTaskVDSCommand, log id: 6164bf23
>> 2017-11-21 10:29:46,974-02 INFO  [org.ovirt.engine.core.vdsbrok
>> er.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-32)
>> [7b755e5d] FINISH, SPMClearTaskVDSCommand, log id: 575b7d94
>> 2017-11-21 10:29:46,980-02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
>> (org.ovirt.thread.pool-6-thread-32) [7b755e5d]
>> BaseAsyncTask::removeTaskFromDB: Removed task
>> 'f585094e-d892-4840-af64-663571cfd35f' from DataBase
>> 2017-11-21 10:29:46,980-02 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
>> (org.ovirt.thread.pool-6-thread-32) [7b755e5d]
>> CommandAsyncTask::HandleEndActionResult [within thread]: Removing
>> CommandMultiAsyncTasks object for entity '785b30c0-a425-4ad0-9a68-9740d
>> 2c9dc1b'
>> 2017-11-21 10:29:47,002-02 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
>> (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b6378408a9d] Ending
>> command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand'
>> with failure.
>> 2017-11-21 10:29:47,005-02 INFO 
[org.ovirt.engine.core.utils.transaction.TransactionSupport]
>> (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>> transaction rolled back
>> 2017-11-21 10:29:47,017-02 ERROR [org.ovirt.engine.core.dal.dbb
>> roker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler6)
>> [70cc2ffa-2414-4a00-9e24-6b6378408a9d] EVENT_ID:
>> USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Correlation ID:
>> 70cc2ffa-2414-4a00-9e24-6b6378408a9d, Job ID:
>> ec197072-7c38-42b6-9aef-99635d4ee135, Call Stack: null, Custom ID:
>> null, Custom Event ID: -1, Message: Failed to delete snapshot
'<UNKNOWN>'
>> for VM 'proxy03'.
>> 2017-11-21 10:29:47,017-02 ERROR
[org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller]
>> (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b6378408a9d] Failed
>> invoking callback end method 'onFailed' for command
>> 'a84519fe-6b23-4084-84a2-b7964cbcde26' with exception 'null',
the
>> callback is marked for end method retries
>> [root@ovirt ovirt-engine]#
>>
>>
>> This is an automatic delete, it caused by some error on my backup script.
>>
>> I am looking for the the Event ID on postgres to identify the error.
>>
>>
>> Atenciosamente,
>> Arthur Melo
>> Linux User #302250
>>
>>
>> 2017-11-21 10:26 GMT-02:00 Benny Zlotnik <bzlotnik(a)redhat.com&gt;:
>>
>>> Please attach the full engine log (at least from the moment you
>>> attempted the to delete).
>>> Do you have access to the host the VM is running on? The vdsm log is
>>> available at /var/log/vdsm/vdsm.log
>>>
>>> On Tue, Nov 21, 2017 at 2:17 PM, Arthur Melo <arthur(a)afabrica.net&gt;
>>> wrote:
>>>
>>>> engine.log
>>>> ------------------
>>>> 2017-11-21 10:15:02,536-02 ERROR [org.ovirt.engine.core.dal.dbb
>>>> roker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler2)
>>>> [70cc2ffa-2414-4a00-9e24-6b6378408a9d] EVENT_ID:
>>>> USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Correlation ID:
>>>> 70cc2ffa-2414-4a00-9e24-6b6378408a9d, Job ID:
>>>> ec197072-7c38-42b6-9aef-99635d4ee135, Call Stack: null, Custom ID:
>>>> null, Custom Event ID: -1, Message: Failed to delete snapshot
'<UNKNOWN>'
>>>> for VM 'proxy03'.
>>>> 2017-11-21 10:15:02,537-02 ERROR
[org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller]
>>>> (DefaultQuartzScheduler2) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>>>> Failed invoking callback end method 'onFailed' for command
>>>> 'a84519fe-6b23-4084-84a2-b7964cbcde26' with exception
'null', the
>>>> callback is marked for end method retries
>>>> 2017-11-21 10:15:12,551-02 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
>>>> (DefaultQuartzScheduler5) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>>>> Ending command
'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand'
>>>> with failure.
>>>> 2017-11-21 10:15:12,555-02 INFO 
[org.ovirt.engine.core.utils.transaction.TransactionSupport]
>>>> (DefaultQuartzScheduler5) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>>>> transaction rolled back
>>>> 2017-11-21 10:15:12,567-02 ERROR [org.ovirt.engine.core.dal.dbb
>>>> roker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler5)
>>>> [70cc2ffa-2414-4a00-9e24-6b6378408a9d] EVENT_ID:
>>>> USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Correlation ID:
>>>> 70cc2ffa-2414-4a00-9e24-6b6378408a9d, Job ID:
>>>> ec197072-7c38-42b6-9aef-99635d4ee135, Call Stack: null, Custom ID:
>>>> null, Custom Event ID: -1, Message: Failed to delete snapshot
'<UNKNOWN>'
>>>> for VM 'proxy03'.
>>>> 2017-11-21 10:15:12,567-02 ERROR
[org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller]
>>>> (DefaultQuartzScheduler5) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>>>> Failed invoking callback end method 'onFailed' for command
>>>> 'a84519fe-6b23-4084-84a2-b7964cbcde26' with exception
'null', the
>>>> callback is marked for end method retries
>>>> 2017-11-21 10:15:22,582-02 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
>>>> (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>>>> Ending command
'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand'
>>>> with failure.
>>>> 2017-11-21 10:15:22,585-02 INFO 
[org.ovirt.engine.core.utils.transaction.TransactionSupport]
>>>> (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>>>> transaction rolled back
>>>> 2017-11-21 10:15:22,599-02 ERROR [org.ovirt.engine.core.dal.dbb
>>>> roker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler10)
>>>> [70cc2ffa-2414-4a00-9e24-6b6378408a9d] EVENT_ID:
>>>> USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Correlation ID:
>>>> 70cc2ffa-2414-4a00-9e24-6b6378408a9d, Job ID:
>>>> ec197072-7c38-42b6-9aef-99635d4ee135, Call Stack: null, Custom ID:
>>>> null, Custom Event ID: -1, Message: Failed to delete snapshot
'<UNKNOWN>'
>>>> for VM 'proxy03'.
>>>> 2017-11-21 10:15:22,600-02 ERROR
[org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller]
>>>> (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b6378408a9d]
>>>> Failed invoking callback end method 'onFailed' for command
>>>> 'a84519fe-6b23-4084-84a2-b7964cbcde26' with exception
'null', the
>>>> callback is marked for end method retries
>>>> ------------------
>>>>
>>>> I don't have vdsm log. (I don't know why).
>>>>
>>>> Atenciosamente,
>>>> Arthur Melo
>>>> Linux User #302250
>>>>
>>>>
>>>> 2017-11-21 10:14 GMT-02:00 Benny Zlotnik <bzlotnik(a)redhat.com&gt;:
>>>>
>>>>> Please attach engine and vdsm logs
>>>>>
>>>>> On Tue, Nov 21, 2017 at 2:11 PM, Arthur Melo
<arthur(a)afabrica.net&gt;
>>>>> wrote:
>>>>>
>>>>>> Can someone help me with this error?
>>>>>>
>>>>>>
>>>>>> Failed to delete snapshot '<UNKNOWN>' for VM
'proxy03'.
>>>>>>
>>>>>>
>>>>>>
>>>>>> Atenciosamente,
>>>>>> Arthur Melo
>>>>>> Linux User #302250
>>>>>>
>>>>>>
>>>>>> _______________________________________________
>>>>>> Users mailing list
>>>>>> Users(a)ovirt.org
>>>>>> http://lists.ovirt.org/mailman/listinfo/users
>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

Re: [ovirt-users] Error during delete snapshot