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