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@afabrica.net>:
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@redhat.com>:
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@afabrica.net> 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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGroupGUID=808b9847-c42c-40d8-959d-5faff30cbaff
2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af22-d210fabfc8ce
2017-11-21 10:29:15,674-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ description={"Updated":false,"Last Updated":"Fri Nov 17 18:28:47 BRST 2017","Storage Domains":[{"uuid":"425606b4-5aa0-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.dbbroker.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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] FINISH, SetVolumeDescriptionVDSCommand, log id: 2bfd570
2017-11-21 10:29:16,862-02 INFO  [org.ovirt.engine.core.bll.storage.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.storage.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.vdsbroker.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.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeVdsBrokerCommand, parameters:
2017-11-21 10:29:16,897-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
2017-11-21 10:29:16,898-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
2017-11-21 10:29:16,898-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGUID=808b9847-c42c-40d8-959d-5faff30cbaff
2017-11-21 10:29:16,898-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af22-d210fabfc8ce
2017-11-21 10:29:16,898-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ size=235520
2017-11-21 10:29:20,138-02 INFO  [org.ovirt.engine.core.vdsbroker.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-5ef678f64a08'
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.storage.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.vdsbroker.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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGroupGUID=808b9847-c42c-40d8-959d-5faff30cbaff
2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af22-d210fabfc8ce
2017-11-21 10:29:20,209-02 INFO  [org.ovirt.engine.core.vdsbroker.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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] FINISH, SetVolumeDescriptionVDSCommand, log id: 111fc33a
2017-11-21 10:29:21,545-02 INFO  [org.ovirt.engine.core.vdsbroker.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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbroker.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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGroupGUID=5919ccc4-b9ad-4213-810b-4f8df08efdf5
2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c11-20ef30bbf839
2017-11-21 10:29:22,496-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ description={"Updated":false,"Last Updated":"Fri Nov 17 18:28:47 BRST 2017","Storage Domains":[{"uuid":"425606b4-5aa0-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.storage.ovfstore.UploadStreamCommand] (org.ovirt.thread.pool-6-thread-2) [58f0924f] Ending command 'org.ovirt.engine.core.bll.storage.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.vdsbroker.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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] FINISH, SetVolumeDescriptionVDSCommand, log id: 7cc59230
2017-11-21 10:29:23,874-02 INFO  [org.ovirt.engine.core.vdsbroker.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.storage.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.storage.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.vdsbroker.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.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeVdsBrokerCommand, parameters:
2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGUID=5919ccc4-b9ad-4213-810b-4f8df08efdf5
2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c11-20ef30bbf839
2017-11-21 10:29:23,916-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ size=235520
2017-11-21 10:29:24,856-02 INFO  [org.ovirt.engine.core.vdsbroker.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.vdsbroker.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-5ef678f64a08'
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.dbbroker.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.vdsbroker.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-083fc4a5c1b8'
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.storage.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.vdsbroker.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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a-000000000038
2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f-61a8d0852bf4
2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGroupGUID=5919ccc4-b9ad-4213-810b-4f8df08efdf5
2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c11-20ef30bbf839
2017-11-21 10:29:26,966-02 INFO  [org.ovirt.engine.core.vdsbroker.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.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] FINISH, SetVolumeDescriptionVDSCommand, log id: 3e073336
2017-11-21 10:29:28,237-02 INFO  [org.ovirt.engine.core.bll.storage.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.SerialChildCommandsExecutionCallback] (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.storage.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.storage.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.vdsbroker.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.vdsbroker.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.storage.ovfstore.UploadStreamCommand] (org.ovirt.thread.pool-6-thread-34) [58f0924f] Ending command 'org.ovirt.engine.core.bll.storage.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.vdsbroker.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.vdsbroker.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.dbbroker.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.vdsbroker.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.vdsbroker.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-083fc4a5c1b8'
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.dbbroker.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.SerialChildCommandsExecutionCallback] (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.storage.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.vdsbroker.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.vdsbroker.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/pSq07hifciMHWlan+xMcaQPka3gyX9tXQ==', session has running commands for user 'admin@internal-authz'.
2017-11-21 10:29:46,974-02 INFO  [org.ovirt.engine.core.vdsbroker.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.vdsbroker.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-9740d2c9dc1b'
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.dbbroker.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@redhat.com>:
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@afabrica.net> wrote:
engine.log
------------------
2017-11-21 10:15:02,536-02 ERROR [org.ovirt.engine.core.dal.dbbroker.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.dbbroker.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.dbbroker.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@redhat.com>:
Please attach engine and vdsm logs

On Tue, Nov 21, 2017 at 2:11 PM, Arthur Melo <arthur@afabrica.net> 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@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users