Sorry for delay.I think the problem is on the oVirt Engine, by the way, the files are attached.Atenciosamente,
Arthur Melo
Linux User #3022502017-11-22 11:29 GMT-02:00 Benny Zlotnik <bzlotnik@redhat.com>:I cannot see the error in the VDSM, please attach the full logs (you can compress them and attach a file)On Tue, Nov 21, 2017 at 2:36 PM, Arthur Melo <arthur@afabrica.net> wrote:I don't have vdsm.log at the engine machine.vdsm.log (host03, where proxy03 is located on)2017-11-21 10:32:48,340-0200 INFO (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.02 seconds (__init__:539)2017-11-21 10:32:48,392-0200 INFO (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:539)2017-11-21 10:32:53,725-0200 INFO (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.03 seconds (__init__:539)2017-11-21 10:32:54,219-0200 INFO (periodic/343) [vdsm.api] START repoStats(options=None) from=internal, task_id=a5c36747-92b8-4659-a64c-5d3b14b7a5fd (api:46) 2017-11-21 10:32:54,219-0200 INFO (periodic/343) [vdsm.api] FINISH repoStats return={u'75c38dd5-92ad-4b88-93be-4d52489db6e3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00043105', 'lastCheck': '6.4', 'valid': True}, u'aeee6368-45bb-4a98-937b-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00787006', 'lastCheck': '6.5', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0169619', 'lastCheck': '7.5', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00485451', 'lastCheck': '6.5', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000404865', 'lastCheck': '6.4', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000347603', 'lastCheck': '3.0', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000443444', 'lastCheck': '7.4', 'valid': True}} from=internal, task_id=a5c36747-92b8-4659-a64 c-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-953 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00974892', 'lastCheck': '4.2', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00352112', 'lastCheck': '5.1', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000560259', 'lastCheck': '4.1', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000447462', 'lastCheck': '4.0', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000477881', 'lastCheck': '0.7', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000480301', 'lastCheck': '5.0', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=46b3675a, task_id=57a40d25-9994-4a9c-953 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0113034', 'lastCheck': '1.6', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0227581', 'lastCheck': '2.6', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0142187', 'lastCheck': '1.6', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000430952', 'lastCheck': '1.5', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000477881', 'lastCheck': '8.1', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000346374', 'lastCheck': '2.4', 'valid': True}} from=internal, task_id=c844a4cb-22df-4b0d-ad0 f-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-01 2a-000000000038', imgUUID=u'046588d2-0d5d-4901-a fb4-5902f3e9a7b1', volUUID='80ee1579-fa6c-4c8a-bb e1-3ead1c8b28f9', options=None) from=internal, task_id=f7ce7918-fa47-45c3-8c2 6-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-01 2a-000000000038', imgUUID=u'0f7db06e-7f03-46a5-9 8c6-264106ad640a', volUUID=u'dc8248bd-fa5d-4627-a d93-d91b6d55090c', options=None) from=internal, task_id=8533e798-a80b-4334-a88 5-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-01 2a-000000000038', imgUUID=u'12eddfe8-e706-4204-9 5ee-d3ff01bf0db5', volUUID='9b607027-7401-494f-9b 48-40d6a3e4abec', options=None) from=internal, task_id=580f8cae-e632-4297-8b0 f-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-01 2a-000000000038', imgUUID=u'562ca0c9-60b2-419d-a aa2-df6ff10292f6', volUUID='9181c596-93b0-43df-8a b1-b1ee4cb9721b', options=None) from=internal, task_id=e09822f1-8d61-42c7-bed 0-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-01 2a-000000000038', imgUUID=u'bd0c6749-538e-4299-8 91f-f35da6d8a4a3', volUUID='d95b1638-f829-4264-86 67-cd68f26783c0', options=None) from=internal, task_id=f4ecbc87-f805-42e3-a70 8-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-01 2a-000000000038', imgUUID=u'ca424d56-f294-48fb-a 627-72dac02ec315', volUUID='f241aba7-3ae4-432b-b5 5c-9ba95ce10e2c', options=None) from=internal, task_id=85313846-51a8-4c5f-ae6 4-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-01 2a-000000000038', imgUUID=u'c0327f75-15d3-4aa2-9 819-da48694183e2', volUUID='3b846bd2-6698-4cf9-87 1a-4c867a0fc30f', options=None) from=internal, task_id=3e704259-a21b-41bb-9a2 0-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-01 2a-000000000038', imgUUID=u'5c33574c-9b4b-432d-b 61e-62bac8c155fd', volUUID='1ddb9ebc-5c6b-4e73-bc 2a-3e9983cf9a73', options=None) from=internal, task_id=b014dfd6-2fc2-4b86-9d1 4-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-01 2a-000000000038', imgUUID=u'36bf11d9-5456-4f69-8 719-35ed6e0fb305', volUUID='083b0e95-6b45-4904-92 be-b1eba0af4289', options=None) from=internal, task_id=8c1aa585-ed1d-43d4-a70 7-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-01 2a-000000000038', imgUUID=u'd68942d0-2ee1-48f5-8 f14-580b917e835d', volUUID='5997ab7a-2be3-4790-a9 b4-5572da3eeb24', options=None) from=internal, task_id=815cf337-24d4-4d73-8a1 a-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-01 2a-000000000038', imgUUID=u'4fd0ce51-815a-457d-b fd9-1d2c0c2a3f0c', volUUID='e5415881-1bdd-40cc-b2 bb-447cfdffd762', options=None) from=internal, task_id=4b3a0d06-44c6-4f8d-ae6 6-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-01 2a-000000000038', imgUUID=u'ae5b7335-0234-4d39-8 b0d-eaa57f3247be', volUUID='b118bb04-c580-49e8-b2 4d-864f3640fbca', options=None) from=internal, task_id=3600445f-7535-4e10-803 6-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-01 2a-000000000038', imgUUID=u'50e17b7b-3a86-4797-9 c42-8f4562fbf7a5', volUUID='902db022-3300-45d0-9b dc-58c0a2ee7dbc', options=None) from=internal, task_id=012e4d7b-cab1-4a0e-85b c-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-01 2a-000000000038', imgUUID=u'a48e6b30-7d29-477e-8 b94-a2a4ecd83c98', volUUID='e4a1e27c-4dad-4735-86 1c-569cba9bc46f', options=None) from=internal, task_id=5544b693-031a-4f7a-897 2-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-01 2a-000000000038', imgUUID=u'd8d02bb5-be37-45f2-a aaa-2f28e4fcca25', volUUID='c1c7bb81-6dae-4b1d-a5 14-4ec5de053994', options=None) from=internal, task_id=f274c966-dd29-4169-9df e-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-01 2a-000000000038', imgUUID=u'f0886b2c-52d4-4f16-9 a90-2fdf96d0fb6b', volUUID='235b33f4-923c-4cad-91 aa-60e36cae15c3', options=None) from=internal, task_id=addf386d-3769-4bd5-bc3 1-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-961 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0113034', 'lastCheck': '1.1', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00619586', 'lastCheck': '0.2', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0142187', 'lastCheck': '1.0', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000430952', 'lastCheck': '1.2', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.00031821', 'lastCheck': '5.8', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000494404', 'lastCheck': '0.1', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=19fb22c2, task_id=68319311-5407-4559-961 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.014852', 'lastCheck': '6.7', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00619586', 'lastCheck': '7.7', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00615694', 'lastCheck': '6.7', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000408817', 'lastCheck': '6.6', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000499266', 'lastCheck': '3.2', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000494404', 'lastCheck': '7.5', 'valid': True}} from=internal, task_id=8dd40afb-b051-402d-a39 f-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-886 e-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0155751', 'lastCheck': '4.4', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0195332', 'lastCheck': '5.4', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00680802', 'lastCheck': '4.3', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000406155', 'lastCheck': '4.3', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000350002', 'lastCheck': '0.9', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000463385', 'lastCheck': '5.3', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=5e2763e4, task_id=b06ce104-bb68-40dd-886 e-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000602672', 'lastCheck': '1.8', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000958537', 'lastCheck': '2.9', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000524798', 'lastCheck': '1.8', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000431355', 'lastCheck': '1.7', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000350002', 'lastCheck': '8.3', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000406714', 'lastCheck': '2.7', 'valid': True}} from=internal, task_id=e82beb91-82d2-4d17-957 b-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-8eb 7-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000602672', 'lastCheck': '1.3', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00734942', 'lastCheck': '0.5', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000524798', 'lastCheck': '1.2', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000431355', 'lastCheck': '1.4', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.00034744', 'lastCheck': '6.0', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000485543', 'lastCheck': '0.3', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=4aaa55b3, task_id=0ccfc73e-4876-436a-8eb 7-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00292128', 'lastCheck': '7.0', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00734942', 'lastCheck': '8.0', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.005357', 'lastCheck': '6.9', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000389392', 'lastCheck': '6.8', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000338751', 'lastCheck': '3.5', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000485543', 'lastCheck': '7.8', 'valid': True}} from=internal, task_id=b22332d1-1cd2-417d-bf8 3-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-a94 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00467249', 'lastCheck': '4.6', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00584804', 'lastCheck': '5.6', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00652665', 'lastCheck': '4.6', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000449782', 'lastCheck': '4.5', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000409327', 'lastCheck': '1.1', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.00046967', 'lastCheck': '5.5', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=fe4bc0a, task_id=a4eda238-199c-4346-a94 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00316746', 'lastCheck': '2.0', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00681892', 'lastCheck': '3.0', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00840636', 'lastCheck': '2.0', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000503123', 'lastCheck': '1.9', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000342223', 'lastCheck': '0.2', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000551599', 'lastCheck': '2.9', 'valid': True}} from=internal, task_id=b79c478b-c40a-4e0e-8aa d-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-01 2a-000000000038', imgUUID=u'046588d2-0d5d-4901-a fb4-5902f3e9a7b1', volUUID='80ee1579-fa6c-4c8a-bb e1-3ead1c8b28f9', options=None) from=internal, task_id=09750ed6-c691-4c61-817 a-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-01 2a-000000000038', imgUUID=u'0f7db06e-7f03-46a5-9 8c6-264106ad640a', volUUID=u'dc8248bd-fa5d-4627-a d93-d91b6d55090c', options=None) from=internal, task_id=68c8aa9a-fb36-498e-bfe b-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-01 2a-000000000038', imgUUID=u'12eddfe8-e706-4204-9 5ee-d3ff01bf0db5', volUUID='9b607027-7401-494f-9b 48-40d6a3e4abec', options=None) from=internal, task_id=fafccdb4-06b8-4442-a01 f-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-01 2a-000000000038', imgUUID=u'562ca0c9-60b2-419d-a aa2-df6ff10292f6', volUUID='9181c596-93b0-43df-8a b1-b1ee4cb9721b', options=None) from=internal, task_id=a8e36efd-c050-43aa-9e3 d-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-01 2a-000000000038', imgUUID=u'bd0c6749-538e-4299-8 91f-f35da6d8a4a3', volUUID='d95b1638-f829-4264-86 67-cd68f26783c0', options=None) from=internal, task_id=2ec682b8-e99b-4383-b91 7-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-01 2a-000000000038', imgUUID=u'ca424d56-f294-48fb-a 627-72dac02ec315', volUUID='f241aba7-3ae4-432b-b5 5c-9ba95ce10e2c', options=None) from=internal, task_id=78b3c805-a930-4b63-aca d-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-01 2a-000000000038', imgUUID=u'c0327f75-15d3-4aa2-9 819-da48694183e2', volUUID='3b846bd2-6698-4cf9-87 1a-4c867a0fc30f', options=None) from=internal, task_id=3a243657-8264-4c06-ae5 7-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-01 2a-000000000038', imgUUID=u'5c33574c-9b4b-432d-b 61e-62bac8c155fd', volUUID='1ddb9ebc-5c6b-4e73-bc 2a-3e9983cf9a73', options=None) from=internal, task_id=c6993c71-d2d5-41bd-900 0-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-01 2a-000000000038', imgUUID=u'36bf11d9-5456-4f69-8 719-35ed6e0fb305', volUUID='083b0e95-6b45-4904-92 be-b1eba0af4289', options=None) from=internal, task_id=5bd3e2e2-9410-4aa5-8ae 2-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-01 2a-000000000038', imgUUID=u'd68942d0-2ee1-48f5-8 f14-580b917e835d', volUUID='5997ab7a-2be3-4790-a9 b4-5572da3eeb24', options=None) from=internal, task_id=768ec546-bf3b-405a-992 d-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-01 2a-000000000038', imgUUID=u'4fd0ce51-815a-457d-b fd9-1d2c0c2a3f0c', volUUID='e5415881-1bdd-40cc-b2 bb-447cfdffd762', options=None) from=internal, task_id=b238b726-7bd7-4f3c-819 8-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-01 2a-000000000038', imgUUID=u'ae5b7335-0234-4d39-8 b0d-eaa57f3247be', volUUID='b118bb04-c580-49e8-b2 4d-864f3640fbca', options=None) from=internal, task_id=734612f4-7e27-4533-872 6-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-01 2a-000000000038', imgUUID=u'50e17b7b-3a86-4797-9 c42-8f4562fbf7a5', volUUID='902db022-3300-45d0-9b dc-58c0a2ee7dbc', options=None) from=internal, task_id=b412232b-1634-48b9-87c 8-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-01 2a-000000000038', imgUUID=u'a48e6b30-7d29-477e-8 b94-a2a4ecd83c98', volUUID='e4a1e27c-4dad-4735-86 1c-569cba9bc46f', options=None) from=internal, task_id=fd3faa5c-db77-463d-82a 7-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-01 2a-000000000038', imgUUID=u'd8d02bb5-be37-45f2-a aaa-2f28e4fcca25', volUUID='c1c7bb81-6dae-4b1d-a5 14-4ec5de053994', options=None) from=internal, task_id=54a8abaa-8a2b-454e-866 f-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-01 2a-000000000038', imgUUID=u'f0886b2c-52d4-4f16-9 a90-2fdf96d0fb6b', volUUID='235b33f4-923c-4cad-91 aa-60e36cae15c3', options=None) from=internal, task_id=d90dcc04-6ae8-4ca8-8ed e-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-9b8 9-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00316746', 'lastCheck': '1.5', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00385945', 'lastCheck': '0.7', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00840636', 'lastCheck': '1.4', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000503123', 'lastCheck': '1.6', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000342223', 'lastCheck': '6.2', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000397598', 'lastCheck': '0.5', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=605ff78e, task_id=43ed860c-719e-4080-9b8 9-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00331356', 'lastCheck': '7.1', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00385945', 'lastCheck': '8.1', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00477843', 'lastCheck': '7.1', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000409132', 'lastCheck': '7.0', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000449765', 'lastCheck': '3.6', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000397598', 'lastCheck': '7.9', 'valid': True}} from=internal, task_id=3d7a53d1-917a-40df-8ca 9-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-a9e 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00589212', 'lastCheck': '5.8', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00830664', 'lastCheck': '6.8', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00458526', 'lastCheck': '5.8', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000474598', 'lastCheck': '5.7', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000422617', 'lastCheck': '2.3', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000489315', 'lastCheck': '6.6', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=3d48c75f, task_id=cbeb394d-1682-464f-a9e 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000473767', 'lastCheck': '2.3', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0133196', 'lastCheck': '3.2', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0043482', 'lastCheck': '2.2', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000369036', 'lastCheck': '2.1', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000354937', 'lastCheck': '0.4', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000524776', 'lastCheck': '3.0', 'valid': True}} from=internal, task_id=07f599c7-11c2-4b9a-923 e-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-b7c c-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000485221', 'lastCheck': '1.9', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00717925', 'lastCheck': '2.9', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00925524', 'lastCheck': '1.9', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00040099', 'lastCheck': '1.8', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000347874', 'lastCheck': '0.1', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.00063195', 'lastCheck': '2.7', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=116b15b9, task_id=ed8ead0d-f585-4a1f-b7c c-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000485221', 'lastCheck': '7.3', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00717925', 'lastCheck': '8.3', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00925524', 'lastCheck': '7.3', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00040099', 'lastCheck': '7.2', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000347874', 'lastCheck': '3.8', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.00063195', 'lastCheck': '8.1', 'valid': True}} from=internal, task_id=8723cedd-907e-40dc-928 9-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-978 2-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0104569', 'lastCheck': '7.5', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00748768', 'lastCheck': '8.5', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0045552', 'lastCheck': '7.5', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000487076', 'lastCheck': '7.4', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000418393', 'lastCheck': '4.0', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.00045539', 'lastCheck': '8.4', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=5a64ac79, task_id=78bdb2f2-c3ac-48c2-978 2-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000490637', 'lastCheck': '2.4', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000496188', 'lastCheck': '2.4', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000647866', 'lastCheck': '2.4', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000485272', 'lastCheck': '2.3', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000350738', 'lastCheck': '0.6', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000478362', 'lastCheck': '3.1', 'valid': True}} from=internal, task_id=5ff4e723-4b55-4043-af6 c-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-01 2a-000000000038', imgUUID=u'046588d2-0d5d-4901-a fb4-5902f3e9a7b1', volUUID='80ee1579-fa6c-4c8a-bb e1-3ead1c8b28f9', options=None) from=internal, task_id=812c98fb-55fa-4390-bea 9-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-01 2a-000000000038', imgUUID=u'0f7db06e-7f03-46a5-9 8c6-264106ad640a', volUUID=u'dc8248bd-fa5d-4627-a d93-d91b6d55090c', options=None) from=internal, task_id=982fa714-367a-4874-8b0 8-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-01 2a-000000000038', imgUUID=u'12eddfe8-e706-4204-9 5ee-d3ff01bf0db5', volUUID='9b607027-7401-494f-9b 48-40d6a3e4abec', options=None) from=internal, task_id=4b59c0d4-d62b-481b-9e9 a-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-01 2a-000000000038', imgUUID=u'562ca0c9-60b2-419d-a aa2-df6ff10292f6', volUUID='9181c596-93b0-43df-8a b1-b1ee4cb9721b', options=None) from=internal, task_id=916e3f3c-710b-45f5-bd1 b-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-01 2a-000000000038', imgUUID=u'bd0c6749-538e-4299-8 91f-f35da6d8a4a3', volUUID='d95b1638-f829-4264-86 67-cd68f26783c0', options=None) from=internal, task_id=c7f40832-eab1-4636-955 9-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-01 2a-000000000038', imgUUID=u'ca424d56-f294-48fb-a 627-72dac02ec315', volUUID='f241aba7-3ae4-432b-b5 5c-9ba95ce10e2c', options=None) from=internal, task_id=b4e1683c-ae76-4af5-a2b a-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-01 2a-000000000038', imgUUID=u'c0327f75-15d3-4aa2-9 819-da48694183e2', volUUID='3b846bd2-6698-4cf9-87 1a-4c867a0fc30f', options=None) from=internal, task_id=1d43b194-c24a-45c1-9a2 2-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-01 2a-000000000038', imgUUID=u'5c33574c-9b4b-432d-b 61e-62bac8c155fd', volUUID='1ddb9ebc-5c6b-4e73-bc 2a-3e9983cf9a73', options=None) from=internal, task_id=e16285b2-139b-4563-ae1 9-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-01 2a-000000000038', imgUUID=u'36bf11d9-5456-4f69-8 719-35ed6e0fb305', volUUID='083b0e95-6b45-4904-92 be-b1eba0af4289', options=None) from=internal, task_id=0d75f8e1-8e1f-45c1-87d b-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-01 2a-000000000038', imgUUID=u'd68942d0-2ee1-48f5-8 f14-580b917e835d', volUUID='5997ab7a-2be3-4790-a9 b4-5572da3eeb24', options=None) from=internal, task_id=38ce3a1d-1de6-41fb-99a f-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-01 2a-000000000038', imgUUID=u'4fd0ce51-815a-457d-b fd9-1d2c0c2a3f0c', volUUID='e5415881-1bdd-40cc-b2 bb-447cfdffd762', options=None) from=internal, task_id=c393da25-6b94-4bda-b5a 0-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-01 2a-000000000038', imgUUID=u'ae5b7335-0234-4d39-8 b0d-eaa57f3247be', volUUID='b118bb04-c580-49e8-b2 4d-864f3640fbca', options=None) from=internal, task_id=0702d492-bd44-4954-a09 f-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-01 2a-000000000038', imgUUID=u'50e17b7b-3a86-4797-9 c42-8f4562fbf7a5', volUUID='902db022-3300-45d0-9b dc-58c0a2ee7dbc', options=None) from=internal, task_id=9932fcbf-c5e9-4929-9b1 7-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-01 2a-000000000038', imgUUID=u'a48e6b30-7d29-477e-8 b94-a2a4ecd83c98', volUUID='e4a1e27c-4dad-4735-86 1c-569cba9bc46f', options=None) from=internal, task_id=b4f6d023-31c3-40e6-b97 7-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-01 2a-000000000038', imgUUID=u'd8d02bb5-be37-45f2-a aaa-2f28e4fcca25', volUUID='c1c7bb81-6dae-4b1d-a5 14-4ec5de053994', options=None) from=internal, task_id=eac2b508-c553-48a0-adb 9-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-01 2a-000000000038', imgUUID=u'f0886b2c-52d4-4f16-9 a90-2fdf96d0fb6b', volUUID='235b33f4-923c-4cad-91 aa-60e36cae15c3', options=None) from=internal, task_id=eea7dad4-75e2-48ad-b84 e-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-9c9 a-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00675086', 'lastCheck': '2.7', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00947756', 'lastCheck': '2.6', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00622928', 'lastCheck': '2.6', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000379158', 'lastCheck': '2.5', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000417515', 'lastCheck': '0.8', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000524652', 'lastCheck': '3.4', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=d08b563, task_id=18b273c7-bd84-4c07-9c9 a-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00675086', 'lastCheck': '7.5', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00947756', 'lastCheck': '7.5', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00622928', 'lastCheck': '7.5', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000379158', 'lastCheck': '7.4', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000417515', 'lastCheck': '4.0', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000524652', 'lastCheck': '8.3', 'valid': True}} from=internal, task_id=2c55d8e7-8b6a-4056-885 5-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-941 1-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-587a ab3daec3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00633629', 'lastCheck': '7.7', 'valid': True}, u'425606b4-5aa0-4548-8b3f-61a8 d0852bf4': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0142374', 'lastCheck': '7.7', 'valid': True}, u'5f0f31cc-bd1d-4a17-b99f-65e0 8007ac83': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000593453', 'lastCheck': '7.7', 'valid': True}, u'6e71472a-cb5d-478c-a05f-2dba fbf6ffaa': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000385028', 'lastCheck': '7.6', 'valid': True}, u'0048460a-9fc0-45c8-851d-86b1 7f872827': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000419577', 'lastCheck': '4.2', 'valid': True}, u'133d2fbd-b905-45f8-860a-cd3e 72f3f49d': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000364547', 'lastCheck': '8.6', 'valid': True}} from=::ffff:192.168.254.80,503 14, flow_id=2d6c655b, task_id=d3853c42-2d16-408a-941 1-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.log2017-11-21 10:29:15,674-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters: 2017-11-21 10:29:15,674-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a -000000000038 2017-11-21 10:29:15,674-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f -61a8d0852bf4 2017-11-21 10:29:15,674-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGroupGUID=808b9847-c42c-4 0d8-959d-5faff30cbaff 2017-11-21 10:29:15,674-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af2 2-d210fabfc8ce 2017-11-21 10:29:15,674-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ description={"Updated":false," Last Updated":"Fri Nov 17 18:28:47 BRST 2017","Storage Domains":[{"uuid":"425606b4-5a a0-4548-8b3f-61a8d0852bf4"}]," Disk Description":"OVF_STORE"} 2017-11-21 10:29:16,693-02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] Ending command 'org.ovirt.engine.core.bll.sna pshots.RemoveSnapshotCommand' with failure. 2017-11-21 10:29:16,696-02 INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] transaction rolled back 2017-11-21 10:29:16,708-02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo gDirector] (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_ FAILURE(357), Correlation ID: 70cc2ffa-2414-4a00-9e24-6b6378 408a9d, Job ID: ec197072-7c38-42b6-9aef-99635d 4ee135, 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-6b637 8408a9d] Failed invoking callback end method 'onFailed' for command 'a84519fe-6b23-4084-84a2-b7964 cbcde26' 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.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] FINISH, SetVolumeDescriptionVDSCommand , log id: 2bfd570 2017-11-21 10:29:16,862-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamComm and] (DefaultQuartzScheduler2) [58f0924f] Lock Acquired to object 'EngineLock:{exclusiveLocks='' , sharedLocks='[5386322c-bf91-4b f5-8507-128f7473aa8d=VDS_EXECU TION]'}' 2017-11-21 10:29:16,897-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamComm and] (DefaultQuartzScheduler2) [58f0924f] Running command: UploadStreamCommand internal: true. Entities affected : ID: 425606b4-5aa0-4548-8b3f-61a8d0 852bf4 Type: Storage 2017-11-21 10:29:16,897-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] START, UploadStreamVDSCommand(HostNam e = host01-dc1, UploadStreamVDSCommandParamete rs:{runAsync='true', hostId='5386322c-bf91-4bf5-850 7-128f7473aa8d'}), log id: 78526132 2017-11-21 10:29:16,897-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] -- executeVdsBrokerCommand, parameters: 2017-11-21 10:29:16,897-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a -000000000038 2017-11-21 10:29:16,898-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f -61a8d0852bf4 2017-11-21 10:29:16,898-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGUID=808b9847-c42c-40d8-9 59d-5faff30cbaff 2017-11-21 10:29:16,898-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af2 2-d210fabfc8ce 2017-11-21 10:29:16,898-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ size=235520 2017-11-21 10:29:20,138-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] FINISH, UploadStreamVDSCommand, log id: 78526132 2017-11-21 10:29:20,163-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler2) [58f0924f] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'd73dc4e7-e0b8-4a19-a672-5ef67 8f64a08' 2017-11-21 10:29:20,163-02 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler2) [58f0924f] CommandMultiAsyncTasks::attach Task: Attaching task '5fe5e889-1065-4e77-834b-71620 e2f23e5' to command 'd73dc4e7-e0b8-4a19-a672-5ef67 8f64a08'. 2017-11-21 10:29:20,186-02 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler2) [58f0924f] Adding task '5fe5e889-1065-4e77-834b-71620 e2f23e5' (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::startPollingTas k: Starting to poll task '5fe5e889-1065-4e77-834b-71620 e2f23e5'. 2017-11-21 10:29:20,205-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamComm and] (DefaultQuartzScheduler2) [58f0924f] Lock freed to object 'EngineLock:{exclusiveLocks='' , sharedLocks='[5386322c-bf91-4b f5-8507-128f7473aa8d=VDS_EXECU TION]'}' 2017-11-21 10:29:20,209-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] START, SetVolumeDescriptionVDSCommand ( SetVolumeDescriptionVDSCommand Parameters:{runAsync='true', storagePoolId='59e6568b-02cd-0 3ad-012a-000000000038', ignoreFailoverLimit='false', storageDomainId='425606b4-5aa0 -4548-8b3f-61a8d0852bf4', imageGroupId='808b9847-c42c-40 d8-959d-5faff30cbaff', imageId='f9d2654b-9f27-4e60-af 22-d210fabfc8ce'}), log id: 111fc33a 2017-11-21 10:29:20,209-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters: 2017-11-21 10:29:20,209-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a -000000000038 2017-11-21 10:29:20,209-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f -61a8d0852bf4 2017-11-21 10:29:20,209-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGroupGUID=808b9847-c42c-4 0d8-959d-5faff30cbaff 2017-11-21 10:29:20,209-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=f9d2654b-9f27-4e60-af2 2-d210fabfc8ce 2017-11-21 10:29:20,209-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ description={"Updated":true,"S ize":235520,"Last Updated":"Tue Nov 21 10:29:15 BRST 2017","Storage Domains":[{"uuid":"425606b4-5a a0-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.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] FINISH, SetVolumeDescriptionVDSCommand , log id: 111fc33a 2017-11-21 10:29:21,545-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] START, SetVolumeDescriptionVDSCommand ( SetVolumeDescriptionVDSCommand Parameters:{runAsync='true', storagePoolId='59e6568b-02cd-0 3ad-012a-000000000038', ignoreFailoverLimit='false', storageDomainId='425606b4-5aa0 -4548-8b3f-61a8d0852bf4', imageGroupId='5919ccc4-b9ad-42 13-810b-4f8df08efdf5', imageId='85a0eb12-2d70-4ae1-8c 11-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-71620 e2f23e5' (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.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters: 2017-11-21 10:29:22,496-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a -000000000038 2017-11-21 10:29:22,496-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (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::onTaskEndSucces s: Task '5fe5e889-1065-4e77-834b-71620 e2f23e5' (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.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGroupGUID=5919ccc4-b9ad-4 213-810b-4f8df08efdf5 2017-11-21 10:29:22,496-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c1 1-20ef30bbf839 2017-11-21 10:29:22,496-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ description={"Updated":false," Last Updated":"Fri Nov 17 18:28:47 BRST 2017","Storage Domains":[{"uuid":"425606b4-5a a0-4548-8b3f-61a8d0852bf4"}]," Disk Description":"OVF_STORE"} 2017-11-21 10:29:22,498-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler7) [5dee72f] CommandAsyncTask::endActionIfN ecessary: All tasks of command 'd73dc4e7-e0b8-4a19-a672-5ef67 8f64a08' 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-5ef67 8f64a08'): calling endAction '. 2017-11-21 10:29:22,498-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-threa d-2) [5dee72f] CommandAsyncTask::endCommandAc tion [within thread] context: Attempting to endAction 'UploadStream', 2017-11-21 10:29:22,505-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamComm and] (org.ovirt.thread.pool-6-threa d-2) [58f0924f] Ending command 'org.ovirt.engine.core.bll.sto rage.ovfstore.UploadStreamComm and' successfully. 2017-11-21 10:29:22,511-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-threa d-2) [58f0924f] CommandAsyncTask::HandleEndAct ionResult [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-threa d-2) [58f0924f] CommandAsyncTask::HandleEndAct ionResult [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-threa d-2) [58f0924f] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '5fe5e889-1065-4e77-834b-71620 e2f23e5' 2017-11-21 10:29:22,512-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-2) [58f0924f] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParam eters:{runAsync='true', storagePoolId='59e6568b-02cd-0 3ad-012a-000000000038', ignoreFailoverLimit='false', taskId='5fe5e889-1065-4e77-834 b-71620e2f23e5'}), log id: 4a85156f 2017-11-21 10:29:23,873-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] FINISH, SetVolumeDescriptionVDSCommand , log id: 7cc59230 2017-11-21 10:29:23,874-02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-2) [58f0924f] START, HSMClearTaskVDSCommand(HostNam e = host01-dc1, HSMTaskGuidBaseVDSCommandParam eters:{runAsync='true', hostId='5386322c-bf91-4bf5-850 7-128f7473aa8d', taskId='5fe5e889-1065-4e77-834 b-71620e2f23e5'}), log id: 7920c7e6 2017-11-21 10:29:23,889-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamComm and] (DefaultQuartzScheduler2) [58f0924f] Lock Acquired to object 'EngineLock:{exclusiveLocks='' , sharedLocks='[5386322c-bf91-4b f5-8507-128f7473aa8d=VDS_EXECU TION]'}' 2017-11-21 10:29:23,915-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamComm and] (DefaultQuartzScheduler2) [58f0924f] Running command: UploadStreamCommand internal: true. Entities affected : ID: 425606b4-5aa0-4548-8b3f-61a8d0 852bf4 Type: Storage 2017-11-21 10:29:23,916-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] START, UploadStreamVDSCommand(HostNam e = host01-dc1, UploadStreamVDSCommandParamete rs:{runAsync='true', hostId='5386322c-bf91-4bf5-850 7-128f7473aa8d'}), log id: 2fc55e39 2017-11-21 10:29:23,916-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] -- executeVdsBrokerCommand, parameters: 2017-11-21 10:29:23,916-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a -000000000038 2017-11-21 10:29:23,916-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f -61a8d0852bf4 2017-11-21 10:29:23,916-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGUID=5919ccc4-b9ad-4213-8 10b-4f8df08efdf5 2017-11-21 10:29:23,916-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c1 1-20ef30bbf839 2017-11-21 10:29:23,916-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] ++ size=235520 2017-11-21 10:29:24,856-02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-2) [58f0924f] FINISH, HSMClearTaskVDSCommand, log id: 7920c7e6 2017-11-21 10:29:24,856-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-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-threa d-2) [58f0924f] BaseAsyncTask::removeTaskFromD B: Removed task '5fe5e889-1065-4e77-834b-71620 e2f23e5' from DataBase 2017-11-21 10:29:24,861-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-threa d-2) [58f0924f] CommandAsyncTask::HandleEndAct ionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'd73dc4e7-e0b8-4a19-a672-5ef67 8f64a08' 2017-11-21 10:29:26,721-02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (DefaultQuartzScheduler8) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] Ending command 'org.ovirt.engine.core.bll.sna pshots.RemoveSnapshotCommand' with failure. 2017-11-21 10:29:26,725-02 INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (DefaultQuartzScheduler8) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] transaction rolled back 2017-11-21 10:29:26,737-02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo gDirector] (DefaultQuartzScheduler8) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_ FAILURE(357), Correlation ID: 70cc2ffa-2414-4a00-9e24-6b6378 408a9d, Job ID: ec197072-7c38-42b6-9aef-99635d 4ee135, 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-6b637 8408a9d] Failed invoking callback end method 'onFailed' for command 'a84519fe-6b23-4084-84a2-b7964 cbcde26' 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.UploadStreamVDSCo mmand] (DefaultQuartzScheduler2) [58f0924f] FINISH, UploadStreamVDSCommand, log id: 2fc55e39 2017-11-21 10:29:26,922-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler2) [58f0924f] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '874fc31b-f30d-44da-9c85-083fc 4a5c1b8' 2017-11-21 10:29:26,922-02 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler2) [58f0924f] CommandMultiAsyncTasks::attach Task: Attaching task 'e9424be5-5fa9-45fd-9d1d-db952 733670c' to command '874fc31b-f30d-44da-9c85-083fc 4a5c1b8'. 2017-11-21 10:29:26,945-02 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler2) [58f0924f] Adding task 'e9424be5-5fa9-45fd-9d1d-db952 733670c' (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::startPollingTas k: Starting to poll task 'e9424be5-5fa9-45fd-9d1d-db952 733670c'. 2017-11-21 10:29:26,964-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamComm and] (DefaultQuartzScheduler2) [58f0924f] Lock freed to object 'EngineLock:{exclusiveLocks='' , sharedLocks='[5386322c-bf91-4b f5-8507-128f7473aa8d=VDS_EXECU TION]'}' 2017-11-21 10:29:26,966-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] START, SetVolumeDescriptionVDSCommand ( SetVolumeDescriptionVDSCommand Parameters:{runAsync='true', storagePoolId='59e6568b-02cd-0 3ad-012a-000000000038', ignoreFailoverLimit='false', storageDomainId='425606b4-5aa0 -4548-8b3f-61a8d0852bf4', imageGroupId='5919ccc4-b9ad-42 13-810b-4f8df08efdf5', imageId='85a0eb12-2d70-4ae1-8c 11-20ef30bbf839'}), log id: 3e073336 2017-11-21 10:29:26,966-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters: 2017-11-21 10:29:26,966-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ spUUID=59e6568b-02cd-03ad-012a -000000000038 2017-11-21 10:29:26,966-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ sdUUID=425606b4-5aa0-4548-8b3f -61a8d0852bf4 2017-11-21 10:29:26,966-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ imageGroupGUID=5919ccc4-b9ad-4 213-810b-4f8df08efdf5 2017-11-21 10:29:26,966-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ volUUID=85a0eb12-2d70-4ae1-8c1 1-20ef30bbf839 2017-11-21 10:29:26,966-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] ++ description={"Updated":true,"S ize":235520,"Last Updated":"Tue Nov 21 10:29:15 BRST 2017","Storage Domains":[{"uuid":"425606b4-5a a0-4548-8b3f-61a8d0852bf4"}]," Disk Description":"OVF_STORE"} 2017-11-21 10:29:28,223-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescript ionVDSCommand] (DefaultQuartzScheduler2) [58f0924f] FINISH, SetVolumeDescriptionVDSCommand , log id: 3e073336 2017-11-21 10:29:28,237-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdate ForStorageDomainCommand] (DefaultQuartzScheduler2) [58f0924f] Lock freed to object 'EngineLock:{exclusiveLocks='[ 425606b4-5aa0-4548-8b3f-61a8d0 852bf4=STORAGE]', sharedLocks='[59e6568b-02cd-03 ad-012a-000000000038=OVF_UPDAT E]'}' 2017-11-21 10:29:29,784-02 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallb ack] (DefaultQuartzScheduler9) [58f0924f] Command 'ProcessOvfUpdateForStorageDom ain' (id: '10a201e9-d1b4-45f0-99a0-74d61 14ac8b5') waiting on child command id: '874fc31b-f30d-44da-9c85-083fc 4a5c1b8' 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-a5a07 5c1cfde] Lock Acquired to object 'EngineLock:{exclusiveLocks='[ 5cb5e5c4-253b-4ab5-a93f-3661e6 ab54ac=VM]', sharedLocks=''}' 2017-11-21 10:29:31,868-02 INFO [org.ovirt.engine.core.bll.RemoveVmCommand] (org.ovirt.thread.pool-6-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] Running command: RemoveVmCommand internal: false. Entities affected : ID: 5cb5e5c4-253b-4ab5-a93f-3661e6 ab54ac 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-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] START, SetVmStatusVDSCommand( SetVmStatusVDSCommandParameter s:{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-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] 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-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] Lock freed to object 'EngineLock:{exclusiveLocks='[ 5cb5e5c4-253b-4ab5-a93f-3661e6 ab54ac=VM]', sharedLocks=''}' 2017-11-21 10:29:31,902-02 INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveAllVmIma gesCommand] (org.ovirt.thread.pool-6-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] Running command: RemoveAllVmImagesCommand internal: true. Entities affected : ID: 5cb5e5c4-253b-4ab5-a93f-3661e6 ab54ac Type: VM 2017-11-21 10:29:31,930-02 INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCom mand] (org.ovirt.thread.pool-6-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] Running command: RemoveImageCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000 000000 Type: Storage 2017-11-21 10:29:32,002-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupV DSCommand] (org.ovirt.thread.pool-6-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandPara meters:{runAsync='true', storagePoolId='59e6568b-02cd-0 3ad-012a-000000000038', ignoreFailoverLimit='false', storageDomainId='425606b4-5aa0 -4548-8b3f-61a8d0852bf4', imageGroupId='fb163891-3a74-4a bc-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.DeleteImageGroupV DSCommand] (org.ovirt.thread.pool-6-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] 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-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '785b30c0-a425-4ad0-9a68-9740d 2c9dc1b' 2017-11-21 10:29:33,594-02 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] CommandMultiAsyncTasks::attach Task: Attaching task 'f585094e-d892-4840-af64-66357 1cfd35f' to command '785b30c0-a425-4ad0-9a68-9740d 2c9dc1b'. 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-db952 733670c' (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::onTaskEndSucces s: Task 'e9424be5-5fa9-45fd-9d1d-db952 733670c' (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::endActionIfN ecessary: All tasks of command '874fc31b-f30d-44da-9c85-083fc 4a5c1b8' 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-083fc 4a5c1b8'): calling endAction '. 2017-11-21 10:29:33,634-02 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-6-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] Adding task 'f585094e-d892-4840-af64-66357 1cfd35f' (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-threa d-34) [6523c570] CommandAsyncTask::endCommandAc tion [within thread] context: Attempting to endAction 'UploadStream', 2017-11-21 10:29:33,643-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamComm and] (org.ovirt.thread.pool-6-threa d-34) [58f0924f] Ending command 'org.ovirt.engine.core.bll.sto rage.ovfstore.UploadStreamComm and' successfully. 2017-11-21 10:29:33,654-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-threa d-34) [58f0924f] CommandAsyncTask::HandleEndAct ionResult [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-threa d-34) [58f0924f] CommandAsyncTask::HandleEndAct ionResult [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-threa d-34) [58f0924f] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'e9424be5-5fa9-45fd-9d1d-db952 733670c' 2017-11-21 10:29:33,655-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-34) [58f0924f] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParam eters:{runAsync='true', storagePoolId='59e6568b-02cd-0 3ad-012a-000000000038', ignoreFailoverLimit='false', taskId='e9424be5-5fa9-45fd-9d1 d-db952733670c'}), log id: 76cd0e96 2017-11-21 10:29:33,656-02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-34) [58f0924f] START, HSMClearTaskVDSCommand(HostNam e = host01-dc1, HSMTaskGuidBaseVDSCommandParam eters:{runAsync='true', hostId='5386322c-bf91-4bf5-850 7-128f7473aa8d', taskId='e9424be5-5fa9-45fd-9d1 d-db952733670c'}), log id: 6bb3135e 2017-11-21 10:29:33,803-02 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo gDirector] (org.ovirt.thread.pool-6-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] EVENT_ID: USER_REMOVE_VM_FINISHED(113), Correlation ID: 6454d8f7-93e6-47ae-ba9b-a5a075 c1cfde, Job ID: 49662b64-2b05-4b32-acd7-412db9 71e99b, 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-threa d-27) [6454d8f7-93e6-47ae-ba9b-a5a07 5c1cfde] BaseAsyncTask::startPollingTas k: Starting to poll task 'f585094e-d892-4840-af64-66357 1cfd35f'. 2017-11-21 10:29:33,825-02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-34) [58f0924f] FINISH, HSMClearTaskVDSCommand, log id: 6bb3135e 2017-11-21 10:29:33,825-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-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-threa d-34) [58f0924f] BaseAsyncTask::removeTaskFromD B: Removed task 'e9424be5-5fa9-45fd-9d1d-db952 733670c' from DataBase 2017-11-21 10:29:33,830-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-threa d-34) [58f0924f] CommandAsyncTask::HandleEndAct ionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '874fc31b-f30d-44da-9c85-083fc 4a5c1b8' 2017-11-21 10:29:36,879-02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] Ending command 'org.ovirt.engine.core.bll.sna pshots.RemoveSnapshotCommand' with failure. 2017-11-21 10:29:36,883-02 INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] transaction rolled back 2017-11-21 10:29:36,895-02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo gDirector] (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_ FAILURE(357), Correlation ID: 70cc2ffa-2414-4a00-9e24-6b6378 408a9d, Job ID: ec197072-7c38-42b6-9aef-99635d 4ee135, 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-6b637 8408a9d] Failed invoking callback end method 'onFailed' for command 'a84519fe-6b23-4084-84a2-b7964 cbcde26' 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.SerialChildCommandsExecutionCallb ack] (DefaultQuartzScheduler8) [58f0924f] Command 'ProcessOvfUpdateForStorageDom ain' id: '10a201e9-d1b4-45f0-99a0-74d61 14ac8b5' child commands '[d73dc4e7-e0b8-4a19-a672-5ef6 78f64a08, 874fc31b-f30d-44da-9c85-083fc4 a5c1b8]' executions were completed, status 'SUCCEEDED' 2017-11-21 10:29:40,974-02 INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdate ForStorageDomainCommand] (DefaultQuartzScheduler5) [58f0924f] Ending command 'org.ovirt.engine.core.bll.sto rage.ovfstore.ProcessOvfUpdate ForStorageDomainCommand' 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-66357 1cfd35f' (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::onTaskEndSucces s: Task 'f585094e-d892-4840-af64-66357 1cfd35f' (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::endActionIfN ecessary: All tasks of command '785b30c0-a425-4ad0-9a68-9740d 2c9dc1b' 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-9740d 2c9dc1b'): calling endAction '. 2017-11-21 10:29:45,928-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-threa d-32) [7b755e5d] CommandAsyncTask::endCommandAc tion [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-threa d-32) [7b755e5d] Ending command 'org.ovirt.engine.core.bll.Rem oveVmCommand' successfully. 2017-11-21 10:29:45,946-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-threa d-32) [7b755e5d] CommandAsyncTask::HandleEndAct ionResult [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-threa d-32) [7b755e5d] CommandAsyncTask::HandleEndAct ionResult [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-threa d-32) [7b755e5d] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'f585094e-d892-4840-af64-66357 1cfd35f' 2017-11-21 10:29:45,947-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-32) [7b755e5d] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParam eters:{runAsync='true', storagePoolId='59e6568b-02cd-0 3ad-012a-000000000038', ignoreFailoverLimit='false', taskId='f585094e-d892-4840-af6 4-663571cfd35f'}), log id: 575b7d94 2017-11-21 10:29:45,947-02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-32) [7b755e5d] START, HSMClearTaskVDSCommand(HostNam e = host01-dc1, HSMTaskGuidBaseVDSCommandParam eters:{runAsync='true', hostId='5386322c-bf91-4bf5-850 7-128f7473aa8d', taskId='f585094e-d892-4840-af6 4-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 'N8YCGRnduzKPm0RIBJIstocZIdkPA ukaKCYDXwWncjWW/NhWw7X1/pSq07h ifciMHWlan+xMcaQPka3gyX9tXQ==' , session has running commands for user 'admin@internal-authz'. 2017-11-21 10:29:46,974-02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-32) [7b755e5d] FINISH, HSMClearTaskVDSCommand, log id: 6164bf23 2017-11-21 10:29:46,974-02 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCo mmand] (org.ovirt.thread.pool-6-threa d-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-threa d-32) [7b755e5d] BaseAsyncTask::removeTaskFromD B: Removed task 'f585094e-d892-4840-af64-66357 1cfd35f' from DataBase 2017-11-21 10:29:46,980-02 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-threa d-32) [7b755e5d] CommandAsyncTask::HandleEndAct ionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '785b30c0-a425-4ad0-9a68-9740d 2c9dc1b' 2017-11-21 10:29:47,002-02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] Ending command 'org.ovirt.engine.core.bll.sna pshots.RemoveSnapshotCommand' with failure. 2017-11-21 10:29:47,005-02 INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] transaction rolled back 2017-11-21 10:29:47,017-02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo gDirector] (DefaultQuartzScheduler6) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_ FAILURE(357), Correlation ID: 70cc2ffa-2414-4a00-9e24-6b6378 408a9d, Job ID: ec197072-7c38-42b6-9aef-99635d 4ee135, 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-6b637 8408a9d] Failed invoking callback end method 'onFailed' for command 'a84519fe-6b23-4084-84a2-b7964 cbcde26' 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 #3022502017-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.logOn 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.AuditLo gDirector] (DefaultQuartzScheduler2) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_ FAILURE(357), Correlation ID: 70cc2ffa-2414-4a00-9e24-6b6378 408a9d, Job ID: ec197072-7c38-42b6-9aef-99635d 4ee135, 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-6b637 8408a9d] Failed invoking callback end method 'onFailed' for command 'a84519fe-6b23-4084-84a2-b7964 cbcde26' 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-6b637 8408a9d] Ending command 'org.ovirt.engine.core.bll.sna pshots.RemoveSnapshotCommand' with failure. 2017-11-21 10:15:12,555-02 INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (DefaultQuartzScheduler5) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] transaction rolled back 2017-11-21 10:15:12,567-02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo gDirector] (DefaultQuartzScheduler5) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_ FAILURE(357), Correlation ID: 70cc2ffa-2414-4a00-9e24-6b6378 408a9d, Job ID: ec197072-7c38-42b6-9aef-99635d 4ee135, 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-6b637 8408a9d] Failed invoking callback end method 'onFailed' for command 'a84519fe-6b23-4084-84a2-b7964 cbcde26' 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-6b637 8408a9d] Ending command 'org.ovirt.engine.core.bll.sna pshots.RemoveSnapshotCommand' with failure. 2017-11-21 10:15:22,585-02 INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] transaction rolled back 2017-11-21 10:15:22,599-02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo gDirector] (DefaultQuartzScheduler10) [70cc2ffa-2414-4a00-9e24-6b637 8408a9d] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_ FAILURE(357), Correlation ID: 70cc2ffa-2414-4a00-9e24-6b6378 408a9d, Job ID: ec197072-7c38-42b6-9aef-99635d 4ee135, 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-6b637 8408a9d] Failed invoking callback end method 'onFailed' for command 'a84519fe-6b23-4084-84a2-b7964 cbcde26' 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 #3022502017-11-21 10:14 GMT-02:00 Benny Zlotnik <bzlotnik@redhat.com>:Please attach engine and vdsm logsOn 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