Hi there,
last days we are facing issues with paused VMs (in past it was for few
second to resize lv device), but now it doesn't resume. we migrated to
4.5.2 cluster, this never happened before with the same storage.
there is almost notning in engine log
2022-09-06 09:47:11,160+02 INFO
[org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer]
(ForkJoinPool-1-worker-9) [51eb7178] VM
'cfff0648-6502-4977-95a8-c6f95c723f6d'(cm1.util.prod.hq.slde
v.cz) moved from 'Up' --> 'Paused'
2022-09-06 09:47:11,264+02 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(ForkJoinPool-1-worker-9) [51eb7178] EVENT_ID: VM_PAUSED(1,025), VM
cm1.util.prod.hq.
sldev.cz has been paused.
2022-09-06 09:47:11,271+02 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(ForkJoinPool-1-worker-9) [51eb7178] EVENT_ID: VM_PAUSED_ENOSPC(138), VM
cm1.util.pro
d.hq.sldev.cz has been paused due to no Storage space error.
but there are erros with LVM in vdsmlog. (attached)
ovirt 4.5.2
OS - ovirt-node-ng.
Thank you for any hint.
Jirka
2022-09-06 09:47:00,702+0200 INFO (jsonrpc/1) [api.host] START getAllVmStats() from=::1,60738 (api:48)
2022-09-06 09:47:00,715+0200 INFO (jsonrpc/1) [api.host] FINISH getAllVmStats return={'status': {'code': 0, 'message': 'Done'}, 'statsList': (suppressed)} from=::1,60738 (api:54)
2022-09-06 09:47:00,872+0200 INFO (monitor/cf819cb) [storage.storagedomaincache] Removing domain cf819cb9-a51f-4b7a-baf6-a2a472aae6da from storage domain cache (sdc:211)
2022-09-06 09:47:01,301+0200 WARN (monitor/cf819cb) [storage.lvm] Command ['/sbin/lvm', 'vgs', '--devices', '/dev/mapper/36589cfc0000004b7c76d143cdc41ac27,/dev/mapper/36589cfc000000512813b031ea0c556e6,/dev/mapper/36589cfc000000667f45684cee766d4aa', '--config', 'devices { preferred_names=["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 hints="none" obtain_device_list_from_udev=0 } global { prioritise_write_locks=1 wait_for_locks=1 use_lvmpolld=1 } backup { retain_min=50 retain_days=0 }', '--noheadings', '--units', 'b', '--nosuffix', '--separator', '|', '--ignoreskippedcluster', '-o', 'uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free,lv_count,pv_count,pv_name', 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da'] succeeded with warnings: [' Error reading device /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704 length 512.', ' Failed to read metadata area header on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704', ' WARNING: bad metadata header on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704.', ' WARNING: scanning /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 mda2 failed to read metadata summary.', ' WARNING: repair VG metadata on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 with vgck --updatemetadata.', ' WARNING: Device /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 has size of 15032385536 sectors which is smaller than corresponding PV size of 19756323200 sectors. Was device resized?', ' WARNING: One or more devices used as PVs in VG cf819cb9-a51f-4b7a-baf6-a2a472aae6da have changed sizes.'] (lvm:358)
2022-09-06 09:47:01,458+0200 WARN (monitor/cf819cb) [storage.lvm] Command ['/sbin/lvm', 'vgck', '--devices', '/dev/mapper/36589cfc0000004b7c76d143cdc41ac27', '--config', 'devices { preferred_names=["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 hints="none" obtain_device_list_from_udev=0 } global { prioritise_write_locks=1 wait_for_locks=1 use_lvmpolld=1 } backup { retain_min=50 retain_days=0 }', 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da'] succeeded with warnings: [' Error reading device /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704 length 512.', ' Failed to read metadata area header on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704', ' WARNING: bad metadata header on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704.', ' WARNING: scanning /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 mda2 failed to read metadata summary.', ' WARNING: repair VG metadata on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 with vgck --updatemetadata.', ' WARNING: Device /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 has size of 15032385536 sectors which is smaller than corresponding PV size of 19756323200 sectors. Was device resized?', ' WARNING: One or more devices used as PVs in VG cf819cb9-a51f-4b7a-baf6-a2a472aae6da have changed sizes.'] (lvm:358)
2022-09-06 09:47:02,407+0200 INFO (jsonrpc/5) [api.virt] START getStats() from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:48)
2022-09-06 09:47:02,408+0200 INFO (jsonrpc/5) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'} (api:129)
2022-09-06 09:47:02,408+0200 INFO (jsonrpc/5) [api.virt] FINISH getStats return={'status': {'code': 1, 'message': "Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'}"}} from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:54)
2022-09-06 09:47:02,408+0200 INFO (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2022-09-06 09:47:03,671+0200 INFO (periodic/4) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2452422656, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:03,671+0200 INFO (periodic/4) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=187.59*, wait=187.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=8ca44f25-ca87-45bc-a9e6-8881f2d5e88b (api:48)
2022-09-06 09:47:03,672+0200 INFO (periodic/4) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=8ca44f25-ca87-45bc-a9e6-8881f2d5e88b (api:54)
2022-09-06 09:47:05,487+0200 INFO (jsonrpc/2) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=b5b042f9-278f-4177-8201-9dd7d583a188 (api:48)
2022-09-06 09:47:05,488+0200 INFO (jsonrpc/2) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '5.5', 'delay': '0.000716301', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=b5b042f9-278f-4177-8201-9dd7d583a188 (api:54)
2022-09-06 09:47:05,671+0200 INFO (periodic/0) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2498494464, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:05,672+0200 INFO (periodic/0) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=189.59*, wait=189.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=82f5308d-93be-48dd-b3ff-2a933fb08822 (api:48)
2022-09-06 09:47:05,672+0200 INFO (periodic/0) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=82f5308d-93be-48dd-b3ff-2a933fb08822 (api:54)
2022-09-06 09:47:06,374+0200 INFO (jsonrpc/7) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=35349800-7e40-4b81-a03b-12150edcbb70 (api:48)
2022-09-06 09:47:06,374+0200 INFO (jsonrpc/7) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.4', 'delay': '0.000716301', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=35349800-7e40-4b81-a03b-12150edcbb70 (api:54)
2022-09-06 09:47:07,048+0200 INFO (periodic/4) [vdsm.api] START repoStats(domains=()) from=internal, task_id=e933437f-a30a-4ead-b469-692e2924b958 (api:48)
2022-09-06 09:47:07,049+0200 INFO (periodic/4) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '0.1', 'delay': '0.000419323', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.9', 'delay': '0.000415463', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.2', 'delay': '0.000534916', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '2.0', 'delay': '0.000404016', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=internal, task_id=e933437f-a30a-4ead-b469-692e2924b958 (api:54)
2022-09-06 09:47:07,147+0200 INFO (jsonrpc/4) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:07,235+0200 INFO (jsonrpc/4) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=014d500b-acb9-414a-9afc-df6954d2c35b (api:48)
2022-09-06 09:47:07,236+0200 INFO (jsonrpc/4) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '0.3', 'delay': '0.000419323', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '4.1', 'delay': '0.000415463', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.4', 'delay': '0.000534916', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '2.1', 'delay': '0.000404016', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=014d500b-acb9-414a-9afc-df6954d2c35b (api:54)
2022-09-06 09:47:07,237+0200 INFO (jsonrpc/4) [vdsm.api] START multipath_health() from=::1,39940, task_id=0203d45c-38f4-41f6-ae17-f6a9dfce90a2 (api:48)
2022-09-06 09:47:07,237+0200 INFO (jsonrpc/4) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=0203d45c-38f4-41f6-ae17-f6a9dfce90a2 (api:54)
2022-09-06 09:47:07,254+0200 INFO (jsonrpc/4) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:07,364+0200 INFO (jsonrpc/3) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:07,459+0200 INFO (jsonrpc/3) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=df803b0c-9e2d-4dbc-834d-81df68fedfba (api:48)
2022-09-06 09:47:07,460+0200 INFO (jsonrpc/3) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '0.5', 'delay': '0.000419323', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '4.3', 'delay': '0.000415463', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.6', 'delay': '0.000534916', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '2.4', 'delay': '0.000404016', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=df803b0c-9e2d-4dbc-834d-81df68fedfba (api:54)
2022-09-06 09:47:07,460+0200 INFO (jsonrpc/3) [vdsm.api] START multipath_health() from=::1,39940, task_id=d534e55c-ce6b-4897-b4fe-5462df2fac9a (api:48)
2022-09-06 09:47:07,461+0200 INFO (jsonrpc/3) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=d534e55c-ce6b-4897-b4fe-5462df2fac9a (api:54)
2022-09-06 09:47:07,477+0200 INFO (jsonrpc/3) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:07,662+0200 INFO (jsonrpc/0) [api.host] START getAllVmStats() from=::ffff:10.36.191.25,48392 (api:48)
2022-09-06 09:47:07,676+0200 INFO (jsonrpc/0) [api.host] FINISH getAllVmStats return={'status': {'code': 0, 'message': 'Done'}, 'statsList': (suppressed)} from=::ffff:10.36.191.25,48392 (api:54)
2022-09-06 09:47:07,683+0200 INFO (periodic/1) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2677604352, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:07,684+0200 INFO (periodic/1) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=191.60*, wait=191.60, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=74609d95-302e-4ad5-a990-5ccafccdfba4 (api:48)
2022-09-06 09:47:07,684+0200 INFO (periodic/1) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=74609d95-302e-4ad5-a990-5ccafccdfba4 (api:54)
2022-09-06 09:47:09,972+0200 INFO (monitor/1af18b4) [storage.storagedomaincache] Removing domain 1af18b4e-e197-40e8-a691-7da21d32a6b2 from storage domain cache (sdc:211)
2022-09-06 09:47:09,995+0200 INFO (jsonrpc/2) [api.host] START getStats() from=::ffff:10.36.191.25,48392 (api:48)
2022-09-06 09:47:10,065+0200 INFO (jsonrpc/2) [vdsm.api] START repoStats(domains=()) from=::ffff:10.36.191.25,48392, task_id=e728dcd2-728c-402d-8b93-7e6ddc5b61a2 (api:48)
2022-09-06 09:47:10,066+0200 INFO (jsonrpc/2) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '3.1', 'delay': '0.000419323', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '6.9', 'delay': '0.000415463', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '3.2', 'delay': '0.000534916', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '5.0', 'delay': '0.000404016', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::ffff:10.36.191.25,48392, task_id=e728dcd2-728c-402d-8b93-7e6ddc5b61a2 (api:54)
2022-09-06 09:47:10,066+0200 INFO (jsonrpc/2) [vdsm.api] START multipath_health() from=::ffff:10.36.191.25,48392, task_id=7d46e387-3c29-4184-b0b1-9ce7a1611a12 (api:48)
2022-09-06 09:47:10,067+0200 INFO (jsonrpc/2) [vdsm.api] FINISH multipath_health return={} from=::ffff:10.36.191.25,48392, task_id=7d46e387-3c29-4184-b0b1-9ce7a1611a12 (api:54)
2022-09-06 09:47:10,084+0200 INFO (jsonrpc/2) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::ffff:10.36.191.25,48392 (api:54)
2022-09-06 09:47:10,103+0200 WARN (monitor/1af18b4) [storage.lvm] Command ['/sbin/lvm', 'vgs', '--devices', '/dev/mapper/36589cfc0000004b7c76d143cdc41ac27,/dev/mapper/36589cfc000000512813b031ea0c556e6,/dev/mapper/36589cfc000000667f45684cee766d4aa', '--config', 'devices { preferred_names=["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 hints="none" obtain_device_list_from_udev=0 } global { prioritise_write_locks=1 wait_for_locks=1 use_lvmpolld=1 } backup { retain_min=50 retain_days=0 }', '--noheadings', '--units', 'b', '--nosuffix', '--separator', '|', '--ignoreskippedcluster', '-o', 'uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free,lv_count,pv_count,pv_name', '1af18b4e-e197-40e8-a691-7da21d32a6b2'] succeeded with warnings: [' Error reading device /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704 length 512.', ' Failed to read metadata area header on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704', ' WARNING: bad metadata header on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704.', ' WARNING: scanning /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 mda2 failed to read metadata summary.', ' WARNING: repair VG metadata on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 with vgck --updatemetadata.'] (lvm:358)
2022-09-06 09:47:11,156+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,156+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,161+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onSuspend (vm:6083)
2022-09-06 09:47:11,187+0200 INFO (monitor/6cff1d5) [storage.storagedomaincache] Removing domain 6cff1d5a-3188-407c-b217-ab33d7b92476 from storage domain cache (sdc:211)
2022-09-06 09:47:11,257+0200 WARN (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') device sda out of space (vm:4003)
2022-09-06 09:47:11,258+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,258+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,261+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,261+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,263+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,263+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,265+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,266+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,268+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,268+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,269+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,270+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,272+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,272+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,274+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,274+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,276+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,276+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,277+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,278+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,279+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,280+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,281+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,282+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,283+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,283+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,285+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,285+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,287+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,287+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,289+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,289+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,292+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,292+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,295+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,295+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,298+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,298+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,300+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,301+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,303+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,303+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,305+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,305+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,307+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') abnormal vm stop device ua-7e574c46-24c7-4de1-81ce-700653d126d6 error enospc (vm:5202)
2022-09-06 09:47:11,307+0200 INFO (libvirt/events) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') CPU stopped: onIOError (vm:6083)
2022-09-06 09:47:11,311+0200 WARN (monitor/6cff1d5) [storage.lvm] Command ['/sbin/lvm', 'vgs', '--devices', '/dev/mapper/36589cfc0000004b7c76d143cdc41ac27,/dev/mapper/36589cfc000000512813b031ea0c556e6,/dev/mapper/36589cfc000000667f45684cee766d4aa', '--config', 'devices { preferred_names=["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 hints="none" obtain_device_list_from_udev=0 } global { prioritise_write_locks=1 wait_for_locks=1 use_lvmpolld=1 } backup { retain_min=50 retain_days=0 }', '--noheadings', '--units', 'b', '--nosuffix', '--separator', '|', '--ignoreskippedcluster', '-o', 'uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free,lv_count,pv_count,pv_name', '6cff1d5a-3188-407c-b217-ab33d7b92476'] succeeded with warnings: [' Error reading device /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704 length 512.', ' Failed to read metadata area header on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704', ' WARNING: bad metadata header on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 at 10115372744704.', ' WARNING: scanning /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 mda2 failed to read metadata summary.', ' WARNING: repair VG metadata on /dev/mapper/36589cfc0000004b7c76d143cdc41ac27 with vgck --updatemetadata.'] (lvm:358)
2022-09-06 09:47:11,427+0200 INFO (jsonrpc/7) [api.virt] START getStats() from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:48)
2022-09-06 09:47:11,427+0200 INFO (jsonrpc/7) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'} (api:129)
2022-09-06 09:47:11,427+0200 INFO (jsonrpc/7) [api.virt] FINISH getStats return={'status': {'code': 1, 'message': "Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'}"}} from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:54)
2022-09-06 09:47:11,427+0200 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2022-09-06 09:47:11,670+0200 INFO (periodic/4) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:11,670+0200 INFO (periodic/4) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=195.59*, wait=195.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=7ffc6ec5-6fca-44c2-b66d-b8bf2d2b30e4 (api:48)
2022-09-06 09:47:11,671+0200 INFO (periodic/4) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=7ffc6ec5-6fca-44c2-b66d-b8bf2d2b30e4 (api:54)
2022-09-06 09:47:13,671+0200 INFO (periodic/1) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:13,672+0200 INFO (periodic/1) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=197.59*, wait=197.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=4f519b6c-0548-43d9-b9d6-509e31246efd (api:48)
2022-09-06 09:47:13,672+0200 INFO (periodic/1) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=4f519b6c-0548-43d9-b9d6-509e31246efd (api:54)
2022-09-06 09:47:14,623+0200 INFO (jsonrpc/5) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=a817473b-79b9-4086-9011-deae7ab9dabf (api:48)
2022-09-06 09:47:14,623+0200 INFO (jsonrpc/5) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '4.4', 'delay': '0.000419323', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=a817473b-79b9-4086-9011-deae7ab9dabf (api:54)
2022-09-06 09:47:15,750+0200 INFO (jsonrpc/3) [api.host] START getAllVmStats() from=::1,60738 (api:48)
2022-09-06 09:47:15,761+0200 INFO (jsonrpc/3) [api.host] FINISH getAllVmStats return={'status': {'code': 0, 'message': 'Done'}, 'statsList': (suppressed)} from=::1,60738 (api:54)
2022-09-06 09:47:16,391+0200 INFO (jsonrpc/2) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=487783c2-e634-49f7-954c-e2ee77b244a6 (api:48)
2022-09-06 09:47:16,391+0200 INFO (jsonrpc/2) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.2', 'delay': '0.000419323', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=487783c2-e634-49f7-954c-e2ee77b244a6 (api:54)
2022-09-06 09:47:16,540+0200 INFO (jsonrpc/7) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:16,610+0200 INFO (jsonrpc/7) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=23562271-9325-43de-8c75-76b2a6a282dd (api:48)
2022-09-06 09:47:16,611+0200 INFO (jsonrpc/7) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.4', 'delay': '0.000419323', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.5', 'delay': '0.000646335', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '5.1', 'delay': '0.000534916', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.5', 'delay': '0.000336269', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=23562271-9325-43de-8c75-76b2a6a282dd (api:54)
2022-09-06 09:47:16,611+0200 INFO (jsonrpc/7) [vdsm.api] START multipath_health() from=::1,39940, task_id=8b423167-5241-4002-8509-70ab77dae1f6 (api:48)
2022-09-06 09:47:16,611+0200 INFO (jsonrpc/7) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=8b423167-5241-4002-8509-70ab77dae1f6 (api:54)
2022-09-06 09:47:16,629+0200 INFO (jsonrpc/7) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:17,324+0200 INFO (jsonrpc/4) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:17,408+0200 INFO (jsonrpc/4) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=3a53e3db-f793-4171-99de-1bfabb42ddc7 (api:48)
2022-09-06 09:47:17,409+0200 INFO (jsonrpc/4) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '0.4', 'delay': '0.000681467', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '4.3', 'delay': '0.000646335', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.5', 'delay': '0.000506251', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '2.3', 'delay': '0.000336269', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=3a53e3db-f793-4171-99de-1bfabb42ddc7 (api:54)
2022-09-06 09:47:17,410+0200 INFO (jsonrpc/4) [vdsm.api] START multipath_health() from=::1,39940, task_id=a532a4d6-5174-48da-a08a-28f18a1f1d3e (api:48)
2022-09-06 09:47:17,410+0200 INFO (jsonrpc/4) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=a532a4d6-5174-48da-a08a-28f18a1f1d3e (api:54)
2022-09-06 09:47:17,428+0200 INFO (jsonrpc/4) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:17,671+0200 INFO (periodic/0) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:17,671+0200 INFO (periodic/0) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=201.59*, wait=201.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=4a75dc7c-8866-4f5c-8caf-d9a2c7e6b51f (api:48)
2022-09-06 09:47:17,671+0200 INFO (periodic/0) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=4a75dc7c-8866-4f5c-8caf-d9a2c7e6b51f (api:54)
2022-09-06 09:47:19,672+0200 INFO (periodic/2) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:19,673+0200 INFO (periodic/2) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=203.59*, wait=203.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=8dfbd26b-d5d2-4ec2-8b45-ed86ed6040f7 (api:48)
2022-09-06 09:47:19,673+0200 INFO (periodic/2) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=8dfbd26b-d5d2-4ec2-8b45-ed86ed6040f7 (api:54)
2022-09-06 09:47:21,444+0200 INFO (jsonrpc/3) [api.virt] START getStats() from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:48)
2022-09-06 09:47:21,444+0200 INFO (jsonrpc/3) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'} (api:129)
2022-09-06 09:47:21,444+0200 INFO (jsonrpc/3) [api.virt] FINISH getStats return={'status': {'code': 1, 'message': "Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'}"}} from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:54)
2022-09-06 09:47:21,444+0200 INFO (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2022-09-06 09:47:21,674+0200 INFO (periodic/1) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:21,675+0200 INFO (periodic/1) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=205.59*, wait=205.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=793f536c-3d4d-4924-a7d0-193f6229dffc (api:48)
2022-09-06 09:47:21,675+0200 INFO (periodic/1) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=793f536c-3d4d-4924-a7d0-193f6229dffc (api:54)
2022-09-06 09:47:22,151+0200 INFO (periodic/4) [vdsm.api] START repoStats(domains=()) from=internal, task_id=6de7b558-b46f-4656-8385-4c6b0c4338c6 (api:48)
2022-09-06 09:47:22,152+0200 INFO (periodic/4) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '2.0', 'delay': '0.000681467', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '0.8', 'delay': '0.000646335', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.7', 'delay': '0.000506251', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.1', 'delay': '0.000221367', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=internal, task_id=6de7b558-b46f-4656-8385-4c6b0c4338c6 (api:54)
2022-09-06 09:47:22,713+0200 INFO (jsonrpc/0) [api.host] START getAllVmStats() from=::ffff:10.36.191.25,48392 (api:48)
2022-09-06 09:47:22,725+0200 INFO (jsonrpc/0) [api.host] FINISH getAllVmStats return={'status': {'code': 0, 'message': 'Done'}, 'statsList': (suppressed)} from=::ffff:10.36.191.25,48392 (api:54)
2022-09-06 09:47:24,765+0200 INFO (jsonrpc/7) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=552b33cf-a5e8-4504-8bac-d37072bda5f1 (api:48)
2022-09-06 09:47:24,766+0200 INFO (jsonrpc/7) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '4.6', 'delay': '0.000681467', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=552b33cf-a5e8-4504-8bac-d37072bda5f1 (api:54)
2022-09-06 09:47:25,005+0200 INFO (jsonrpc/1) [api.host] START getStats() from=::ffff:10.36.191.25,48392 (api:48)
2022-09-06 09:47:25,076+0200 INFO (jsonrpc/1) [vdsm.api] START repoStats(domains=()) from=::ffff:10.36.191.25,48392, task_id=df080b7a-def6-40fa-a889-0d681d006cdb (api:48)
2022-09-06 09:47:25,076+0200 INFO (jsonrpc/1) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '4.9', 'delay': '0.000681467', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '2.0', 'delay': '0.000598762', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '3.6', 'delay': '0.000506251', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '4.0', 'delay': '0.000221367', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::ffff:10.36.191.25,48392, task_id=df080b7a-def6-40fa-a889-0d681d006cdb (api:54)
2022-09-06 09:47:25,077+0200 INFO (jsonrpc/1) [vdsm.api] START multipath_health() from=::ffff:10.36.191.25,48392, task_id=08e35e33-6848-4c25-bc3d-313b8c9a14ab (api:48)
2022-09-06 09:47:25,077+0200 INFO (jsonrpc/1) [vdsm.api] FINISH multipath_health return={} from=::ffff:10.36.191.25,48392, task_id=08e35e33-6848-4c25-bc3d-313b8c9a14ab (api:54)
2022-09-06 09:47:25,092+0200 INFO (jsonrpc/1) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::ffff:10.36.191.25,48392 (api:54)
2022-09-06 09:47:25,673+0200 INFO (periodic/1) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:25,674+0200 INFO (periodic/1) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=209.59*, wait=209.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=9c420c5b-af67-42cf-9708-388baa0adeb6 (api:48)
2022-09-06 09:47:25,674+0200 INFO (periodic/1) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=9c420c5b-af67-42cf-9708-388baa0adeb6 (api:54)
2022-09-06 09:47:26,407+0200 INFO (jsonrpc/5) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=4bf63281-d769-4feb-a18f-ae5fb15e09f8 (api:48)
2022-09-06 09:47:26,407+0200 INFO (jsonrpc/5) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.2', 'delay': '0.000681467', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=4bf63281-d769-4feb-a18f-ae5fb15e09f8 (api:54)
2022-09-06 09:47:26,451+0200 INFO (jsonrpc/0) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:26,521+0200 INFO (jsonrpc/0) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=4500a48c-33fe-459e-a859-4a6b53e3ba66 (api:48)
2022-09-06 09:47:26,522+0200 INFO (jsonrpc/0) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.3', 'delay': '0.000681467', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.4', 'delay': '0.000598762', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '5.1', 'delay': '0.000506251', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.4', 'delay': '0.000221367', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=4500a48c-33fe-459e-a859-4a6b53e3ba66 (api:54)
2022-09-06 09:47:26,522+0200 INFO (jsonrpc/0) [vdsm.api] START multipath_health() from=::1,39940, task_id=e9f829ac-0b5c-4ca7-86f0-cde1ca44ccad (api:48)
2022-09-06 09:47:26,523+0200 INFO (jsonrpc/0) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=e9f829ac-0b5c-4ca7-86f0-cde1ca44ccad (api:54)
2022-09-06 09:47:26,538+0200 INFO (jsonrpc/0) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:26,667+0200 INFO (jsonrpc/6) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:26,740+0200 INFO (jsonrpc/6) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=251d3e54-43d4-4409-90b9-87d433917b67 (api:48)
2022-09-06 09:47:26,741+0200 INFO (jsonrpc/6) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.5', 'delay': '0.000681467', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.6', 'delay': '0.000598762', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '5.3', 'delay': '0.000506251', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.6', 'delay': '0.000221367', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=251d3e54-43d4-4409-90b9-87d433917b67 (api:54)
2022-09-06 09:47:26,741+0200 INFO (jsonrpc/6) [vdsm.api] START multipath_health() from=::1,39940, task_id=be32d723-8c9e-46f4-87f1-78cfb06ce9b4 (api:48)
2022-09-06 09:47:26,741+0200 INFO (jsonrpc/6) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=be32d723-8c9e-46f4-87f1-78cfb06ce9b4 (api:54)
2022-09-06 09:47:26,755+0200 INFO (jsonrpc/6) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:27,673+0200 INFO (periodic/4) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:27,674+0200 INFO (periodic/4) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=211.59*, wait=211.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=3ae3cf46-cfee-41a9-93b3-6dbbd3e159ae (api:48)
2022-09-06 09:47:27,674+0200 INFO (periodic/4) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=3ae3cf46-cfee-41a9-93b3-6dbbd3e159ae (api:54)
2022-09-06 09:47:29,674+0200 INFO (periodic/2) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:29,675+0200 INFO (periodic/2) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=213.59*, wait=213.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=0a2ded8d-047a-4dd0-8a4f-d20ec6076523 (api:48)
2022-09-06 09:47:29,675+0200 INFO (periodic/2) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=0a2ded8d-047a-4dd0-8a4f-d20ec6076523 (api:54)
2022-09-06 09:47:30,797+0200 INFO (jsonrpc/7) [api.host] START getAllVmStats() from=::1,60738 (api:48)
2022-09-06 09:47:30,810+0200 INFO (jsonrpc/7) [api.host] FINISH getAllVmStats return={'status': {'code': 0, 'message': 'Done'}, 'statsList': (suppressed)} from=::1,60738 (api:54)
2022-09-06 09:47:31,460+0200 INFO (jsonrpc/5) [api.virt] START getStats() from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:48)
2022-09-06 09:47:31,461+0200 INFO (jsonrpc/5) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'} (api:129)
2022-09-06 09:47:31,461+0200 INFO (jsonrpc/5) [api.virt] FINISH getStats return={'status': {'code': 1, 'message': "Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'}"}} from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:54)
2022-09-06 09:47:31,461+0200 INFO (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2022-09-06 09:47:31,676+0200 INFO (periodic/1) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:31,677+0200 INFO (periodic/1) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=215.59*, wait=215.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=36998c84-8a58-4156-a2be-7adaea539888 (api:48)
2022-09-06 09:47:31,678+0200 INFO (periodic/1) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=36998c84-8a58-4156-a2be-7adaea539888 (api:54)
2022-09-06 09:47:34,838+0200 INFO (jsonrpc/3) [jsonrpc.JsonRpcServer] 4986 requests processed during 3600 seconds (__init__:301)
2022-09-06 09:47:34,897+0200 INFO (jsonrpc/2) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=a9028833-1bd2-41d5-8bbc-603db73ef2ea (api:48)
2022-09-06 09:47:34,898+0200 INFO (jsonrpc/2) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '4.7', 'delay': '0.000589149', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=a9028833-1bd2-41d5-8bbc-603db73ef2ea (api:54)
2022-09-06 09:47:35,675+0200 INFO (periodic/4) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:35,676+0200 INFO (periodic/4) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=219.59*, wait=219.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=695043fe-f07b-420b-a9ed-2d6e3a40a591 (api:48)
2022-09-06 09:47:35,676+0200 INFO (periodic/4) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=695043fe-f07b-420b-a9ed-2d6e3a40a591 (api:54)
2022-09-06 09:47:36,422+0200 INFO (jsonrpc/7) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=ba83dbb3-e4f4-4c17-8d2b-b40da41667b5 (api:48)
2022-09-06 09:47:36,422+0200 INFO (jsonrpc/7) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.2', 'delay': '0.000589149', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=ba83dbb3-e4f4-4c17-8d2b-b40da41667b5 (api:54)
2022-09-06 09:47:36,578+0200 INFO (jsonrpc/4) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:36,663+0200 INFO (jsonrpc/4) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=38eae10f-d699-4c50-8387-428e65227834 (api:48)
2022-09-06 09:47:36,664+0200 INFO (jsonrpc/4) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.5', 'delay': '0.000589149', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.5', 'delay': '0.000547291', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '5.2', 'delay': '0.000611019', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.6', 'delay': '0.000322232', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=38eae10f-d699-4c50-8387-428e65227834 (api:54)
2022-09-06 09:47:36,665+0200 INFO (jsonrpc/4) [vdsm.api] START multipath_health() from=::1,39940, task_id=ca0f3056-9421-481b-8013-a2e53f8276fd (api:48)
2022-09-06 09:47:36,665+0200 INFO (jsonrpc/4) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=ca0f3056-9421-481b-8013-a2e53f8276fd (api:54)
2022-09-06 09:47:36,674+0200 INFO (periodic/0) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='290da928-2642-4977-bbed-00167e068392', volUUID='f98591f5-5918-47fd-9a55-69680b086778') from=internal, task_id=91395f2d-61d7-45b1-9fff-fc09be2c274a (api:48)
2022-09-06 09:47:36,674+0200 INFO (periodic/0) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '2684354560', 'truesize': '2684354560'} from=internal, task_id=91395f2d-61d7-45b1-9fff-fc09be2c274a (api:54)
2022-09-06 09:47:36,675+0200 INFO (periodic/1) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='ab43b5f9-8fc5-4cc1-b0f7-ec43538cc7df', volUUID='9bf32c4b-ea6d-4917-bc2b-990a9185cd66') from=internal, task_id=e97683b9-a47b-4b52-9e43-65737bd8c911 (api:48)
2022-09-06 09:47:36,675+0200 INFO (periodic/1) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '2684354560', 'truesize': '2684354560'} from=internal, task_id=e97683b9-a47b-4b52-9e43-65737bd8c911 (api:54)
2022-09-06 09:47:36,676+0200 INFO (periodic/4) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='f34215f6-bac6-4677-8238-e799c43b8d77', volUUID='2d40edcc-daaf-4640-aa04-7ef9b31c1231') from=internal, task_id=9867f372-d5ae-42db-b4c7-f3b6aa212458 (api:48)
2022-09-06 09:47:36,676+0200 INFO (periodic/4) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '59324235776', 'truesize': '59324235776'} from=internal, task_id=9867f372-d5ae-42db-b4c7-f3b6aa212458 (api:54)
2022-09-06 09:47:36,677+0200 INFO (periodic/0) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='c3421ca0-4409-469d-84e7-8adc44c5badb', volUUID='170d2d1c-00b5-48b4-9c43-9a4d0d254df5') from=internal, task_id=1dbe7b81-7587-4548-8ec9-62d549815f25 (api:48)
2022-09-06 09:47:36,677+0200 INFO (periodic/0) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '2684354560', 'truesize': '2684354560'} from=internal, task_id=1dbe7b81-7587-4548-8ec9-62d549815f25 (api:54)
2022-09-06 09:47:36,677+0200 INFO (periodic/1) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='10d0072f-7b2f-49ab-bb3f-5ca565f623f0', volUUID='df18a483-b263-4462-b3b2-5cbe54406bff') from=internal, task_id=b4f14ed2-19c0-47e1-aaae-9691070ba4b7 (api:48)
2022-09-06 09:47:36,678+0200 INFO (periodic/1) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '15032385536', 'truesize': '15032385536'} from=internal, task_id=b4f14ed2-19c0-47e1-aaae-9691070ba4b7 (api:54)
2022-09-06 09:47:36,678+0200 INFO (periodic/4) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='7e574c46-24c7-4de1-81ce-700653d126d6', volUUID='785958e3-7136-4296-a321-406ac5596e78') from=internal, task_id=6168cbcf-a5ae-4d42-9082-fc6f46a9ec95 (api:48)
2022-09-06 09:47:36,678+0200 INFO (periodic/4) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '2684354560', 'truesize': '2684354560'} from=internal, task_id=6168cbcf-a5ae-4d42-9082-fc6f46a9ec95 (api:54)
2022-09-06 09:47:36,679+0200 INFO (periodic/1) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='8ebdc6ce-908c-48d9-a1c9-6ad8efa7fc15', volUUID='4d7080ae-fbaf-4094-82e5-4355919f6a54') from=internal, task_id=8b982973-f3d5-401c-93c1-331f8308d484 (api:48)
2022-09-06 09:47:36,679+0200 INFO (periodic/1) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '7650410496', 'truesize': '7650410496'} from=internal, task_id=8b982973-f3d5-401c-93c1-331f8308d484 (api:54)
2022-09-06 09:47:36,680+0200 INFO (periodic/1) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='6d8ba42d-84d0-48a0-a58f-0c733c1dfc81', volUUID='2bec82ed-2bb3-44b5-b12b-e2717d33a276') from=internal, task_id=05166a09-c26f-48a5-bd4c-49ef5d8360be (api:48)
2022-09-06 09:47:36,680+0200 INFO (periodic/1) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '7650410496', 'truesize': '7650410496'} from=internal, task_id=05166a09-c26f-48a5-bd4c-49ef5d8360be (api:54)
2022-09-06 09:47:36,680+0200 INFO (periodic/4) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='cd52fc7d-88e6-4c25-bfa2-7a1d8b392fb7', volUUID='e376fe70-fa5c-43d7-bc0e-93bfb0ce42af') from=internal, task_id=ffba1c6c-0974-4c4c-a438-5c309ce53b90 (api:48)
2022-09-06 09:47:36,680+0200 INFO (periodic/4) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '15703474176', 'truesize': '15703474176'} from=internal, task_id=ffba1c6c-0974-4c4c-a438-5c309ce53b90 (api:54)
2022-09-06 09:47:36,681+0200 INFO (periodic/1) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='b493129d-e994-475f-8585-d91b12647694', volUUID='ac0a0d05-274d-4c8b-8977-a2f5be65fa88') from=internal, task_id=bcd0cf9a-22b1-474c-9d76-49a828fb8038 (api:48)
2022-09-06 09:47:36,681+0200 INFO (periodic/1) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '2684354560', 'truesize': '2684354560'} from=internal, task_id=bcd0cf9a-22b1-474c-9d76-49a828fb8038 (api:54)
2022-09-06 09:47:36,682+0200 INFO (periodic/4) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='543e5727-dc94-4a08-8610-93593cffed0a', volUUID='9e4a362a-2db9-4dbf-ae9d-56b60dafcb45') from=internal, task_id=012e3633-83f7-4897-9727-9cd64d162b1d (api:48)
2022-09-06 09:47:36,682+0200 INFO (periodic/4) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '2684354560', 'truesize': '2684354560'} from=internal, task_id=012e3633-83f7-4897-9727-9cd64d162b1d (api:54)
2022-09-06 09:47:36,683+0200 INFO (periodic/1) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='20ef5e53-96b9-4024-a5b4-8f17525fa64a', volUUID='aafc4dd7-909d-4294-99b7-61c7cdf644bf') from=internal, task_id=c9a042d9-7598-41dc-9511-75dda7185a33 (api:48)
2022-09-06 09:47:36,683+0200 INFO (periodic/1) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '2684354560', 'truesize': '2684354560'} from=internal, task_id=c9a042d9-7598-41dc-9511-75dda7185a33 (api:54)
2022-09-06 09:47:36,683+0200 INFO (periodic/4) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='6c415d27-0f01-4ba3-9636-752afca404f5', volUUID='c31666ee-e1d8-4ac9-a6f1-b2d3abaad433') from=internal, task_id=6a9980af-91bc-4fc6-9007-c3244fac253f (api:48)
2022-09-06 09:47:36,683+0200 INFO (periodic/4) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '59726888960', 'truesize': '59726888960'} from=internal, task_id=6a9980af-91bc-4fc6-9007-c3244fac253f (api:54)
2022-09-06 09:47:36,684+0200 INFO (periodic/1) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='a4a9f89e-5fff-433a-898c-a9b84861e74e', volUUID='15b705f7-36ba-49fa-9daa-cf005411187f') from=internal, task_id=1e01ae74-8163-4015-a06e-962d6e5017e2 (api:48)
2022-09-06 09:47:36,684+0200 INFO (periodic/1) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '11005853696', 'truesize': '11005853696'} from=internal, task_id=1e01ae74-8163-4015-a06e-962d6e5017e2 (api:54)
2022-09-06 09:47:36,684+0200 INFO (periodic/4) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='7dad1070-8488-487f-9986-a2fc766d657d', volUUID='903616b6-9460-478a-b0d5-d4633376053f') from=internal, task_id=31744aac-e18d-4af3-bc10-af0dede0a668 (api:48)
2022-09-06 09:47:36,684+0200 INFO (periodic/4) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '2684354560', 'truesize': '2684354560'} from=internal, task_id=31744aac-e18d-4af3-bc10-af0dede0a668 (api:54)
2022-09-06 09:47:36,685+0200 INFO (periodic/0) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='7a9ba44d-09d9-4c06-91dd-bab629ae3b35', volUUID='0af3e4e2-36e0-4e86-854a-0d1463ab12e3') from=internal, task_id=a1074a12-2834-41d5-aaa1-b86b2b5939c8 (api:48)
2022-09-06 09:47:36,685+0200 INFO (periodic/0) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '59592671232', 'truesize': '59592671232'} from=internal, task_id=a1074a12-2834-41d5-aaa1-b86b2b5939c8 (api:54)
2022-09-06 09:47:36,686+0200 INFO (periodic/2) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='3ab6e152-802f-4962-ac8b-b64fbc6618e6', volUUID='53a43bd6-fe59-4a7a-9c9d-0256ec9c8cbe') from=internal, task_id=ea84f7f0-3968-4630-a978-1513f1001e1c (api:48)
2022-09-06 09:47:36,686+0200 INFO (periodic/2) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '61069066240', 'truesize': '61069066240'} from=internal, task_id=ea84f7f0-3968-4630-a978-1513f1001e1c (api:54)
2022-09-06 09:47:36,687+0200 INFO (periodic/2) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='f96e945f-667b-4957-abf8-e6f35dc88c34', volUUID='cbf2d7a2-3d06-4620-bf46-37def1605e7a') from=internal, task_id=475112b7-3501-4e7b-a665-34d60fa78c42 (api:48)
2022-09-06 09:47:36,687+0200 INFO (periodic/2) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '118782689280', 'truesize': '118782689280'} from=internal, task_id=475112b7-3501-4e7b-a665-34d60fa78c42 (api:54)
2022-09-06 09:47:36,687+0200 INFO (periodic/2) [vdsm.api] START getVolumeSize(sdUUID='6cff1d5a-3188-407c-b217-ab33d7b92476', spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', imgUUID='d8f554c7-0b84-467e-8fcd-efc3089146ec', volUUID='ad48aa7e-803e-4071-8289-3056a95f2891') from=internal, task_id=4d3aa3dc-f28d-4d9a-ad46-10b2ec4b84c1 (api:48)
2022-09-06 09:47:36,687+0200 INFO (periodic/2) [vdsm.api] FINISH getVolumeSize return={'apparentsize': '49257906176', 'truesize': '49257906176'} from=internal, task_id=4d3aa3dc-f28d-4d9a-ad46-10b2ec4b84c1 (api:54)
2022-09-06 09:47:36,699+0200 INFO (jsonrpc/4) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:36,795+0200 INFO (jsonrpc/3) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:36,867+0200 INFO (jsonrpc/3) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=6c6bc165-8aa5-4a79-9ef1-e72bf639ee49 (api:48)
2022-09-06 09:47:36,868+0200 INFO (jsonrpc/3) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.7', 'delay': '0.000589149', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.7', 'delay': '0.000547291', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '5.4', 'delay': '0.000611019', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.8', 'delay': '0.000322232', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=6c6bc165-8aa5-4a79-9ef1-e72bf639ee49 (api:54)
2022-09-06 09:47:36,869+0200 INFO (jsonrpc/3) [vdsm.api] START multipath_health() from=::1,39940, task_id=6c23eeca-8296-471c-9c62-87f2a9b2361a (api:48)
2022-09-06 09:47:36,869+0200 INFO (jsonrpc/3) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=6c23eeca-8296-471c-9c62-87f2a9b2361a (api:54)
2022-09-06 09:47:36,887+0200 INFO (jsonrpc/3) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:37,249+0200 INFO (periodic/0) [vdsm.api] START repoStats(domains=()) from=internal, task_id=f7e3ba64-3da1-4ab5-8b27-f50ac872637f (api:48)
2022-09-06 09:47:37,250+0200 INFO (periodic/0) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '0.3', 'delay': '0.000717237', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '4.1', 'delay': '0.000547291', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.4', 'delay': '0.000506341', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '2.1', 'delay': '0.000322232', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=internal, task_id=f7e3ba64-3da1-4ab5-8b27-f50ac872637f (api:54)
2022-09-06 09:47:37,763+0200 INFO (jsonrpc/0) [api.host] START getAllVmStats() from=::ffff:10.36.191.25,48392 (api:48)
2022-09-06 09:47:37,773+0200 INFO (jsonrpc/0) [api.host] FINISH getAllVmStats return={'status': {'code': 0, 'message': 'Done'}, 'statsList': (suppressed)} from=::ffff:10.36.191.25,48392 (api:54)
2022-09-06 09:47:39,676+0200 INFO (periodic/1) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:39,677+0200 INFO (periodic/1) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=223.59*, wait=223.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=902a5588-4fb4-4389-a8dc-72840fe93231 (api:48)
2022-09-06 09:47:39,677+0200 INFO (periodic/1) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=902a5588-4fb4-4389-a8dc-72840fe93231 (api:54)
2022-09-06 09:47:40,016+0200 INFO (jsonrpc/2) [api.host] START getStats() from=::ffff:10.36.191.25,48392 (api:48)
2022-09-06 09:47:40,087+0200 INFO (jsonrpc/2) [vdsm.api] START repoStats(domains=()) from=::ffff:10.36.191.25,48392, task_id=6dcd51f0-3bbd-454e-bb28-2f5ffbb9e77b (api:48)
2022-09-06 09:47:40,088+0200 INFO (jsonrpc/2) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '3.1', 'delay': '0.000717237', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '7.0', 'delay': '0.000547291', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '3.2', 'delay': '0.000506341', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '5.0', 'delay': '0.000322232', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::ffff:10.36.191.25,48392, task_id=6dcd51f0-3bbd-454e-bb28-2f5ffbb9e77b (api:54)
2022-09-06 09:47:40,088+0200 INFO (jsonrpc/2) [vdsm.api] START multipath_health() from=::ffff:10.36.191.25,48392, task_id=8ed95887-0e2c-4140-a163-77df3398f515 (api:48)
2022-09-06 09:47:40,088+0200 INFO (jsonrpc/2) [vdsm.api] FINISH multipath_health return={} from=::ffff:10.36.191.25,48392, task_id=8ed95887-0e2c-4140-a163-77df3398f515 (api:54)
2022-09-06 09:47:40,104+0200 INFO (jsonrpc/2) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::ffff:10.36.191.25,48392 (api:54)
2022-09-06 09:47:41,478+0200 INFO (jsonrpc/7) [api.virt] START getStats() from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:48)
2022-09-06 09:47:41,478+0200 INFO (jsonrpc/7) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'} (api:129)
2022-09-06 09:47:41,479+0200 INFO (jsonrpc/7) [api.virt] FINISH getStats return={'status': {'code': 1, 'message': "Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'}"}} from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:54)
2022-09-06 09:47:41,479+0200 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2022-09-06 09:47:41,613+0200 INFO (jsonrpc/4) [api.virt] START getStats() from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:48)
2022-09-06 09:47:41,613+0200 INFO (jsonrpc/4) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'} (api:129)
2022-09-06 09:47:41,613+0200 INFO (jsonrpc/4) [api.virt] FINISH getStats return={'status': {'code': 1, 'message': "Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'}"}} from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:54)
2022-09-06 09:47:41,613+0200 INFO (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2022-09-06 09:47:41,679+0200 INFO (periodic/0) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:41,679+0200 INFO (periodic/0) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=225.60*, wait=225.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=2770d7c7-479b-46d6-ba49-c1efa9aa0678 (api:48)
2022-09-06 09:47:41,680+0200 INFO (periodic/0) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=2770d7c7-479b-46d6-ba49-c1efa9aa0678 (api:54)
2022-09-06 09:47:45,039+0200 INFO (jsonrpc/0) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=4901e892-10d4-454f-8c71-1941418ac5de (api:48)
2022-09-06 09:47:45,039+0200 INFO (jsonrpc/0) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '4.8', 'delay': '0.000717237', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=4901e892-10d4-454f-8c71-1941418ac5de (api:54)
2022-09-06 09:47:45,677+0200 INFO (periodic/1) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:45,677+0200 INFO (periodic/1) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=229.59*, wait=229.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=9fa60323-44b2-432b-bc79-720c3a122950 (api:48)
2022-09-06 09:47:45,678+0200 INFO (periodic/1) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=9fa60323-44b2-432b-bc79-720c3a122950 (api:54)
2022-09-06 09:47:45,837+0200 INFO (jsonrpc/2) [api.host] START getAllVmStats() from=::1,60738 (api:48)
2022-09-06 09:47:45,852+0200 INFO (jsonrpc/2) [api.host] FINISH getAllVmStats return={'status': {'code': 0, 'message': 'Done'}, 'statsList': (suppressed)} from=::1,60738 (api:54)
2022-09-06 09:47:46,438+0200 INFO (jsonrpc/7) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=5fc3b6b7-58ab-462b-9c2b-d7db171228e1 (api:48)
2022-09-06 09:47:46,439+0200 INFO (jsonrpc/7) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.2', 'delay': '0.000717237', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=5fc3b6b7-58ab-462b-9c2b-d7db171228e1 (api:54)
2022-09-06 09:47:46,756+0200 INFO (jsonrpc/4) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:46,842+0200 INFO (jsonrpc/4) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=c6c2125e-9324-4da3-a084-7f6fe2597ab6 (api:48)
2022-09-06 09:47:46,844+0200 INFO (jsonrpc/4) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.6', 'delay': '0.000717237', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.7', 'delay': '0.000591494', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '5.4', 'delay': '0.000506341', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.7', 'delay': '0.000298594', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=c6c2125e-9324-4da3-a084-7f6fe2597ab6 (api:54)
2022-09-06 09:47:46,844+0200 INFO (jsonrpc/4) [vdsm.api] START multipath_health() from=::1,39940, task_id=c573fe62-afe6-4c0d-b5ed-7561578ec42e (api:48)
2022-09-06 09:47:46,845+0200 INFO (jsonrpc/4) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=c573fe62-afe6-4c0d-b5ed-7561578ec42e (api:54)
2022-09-06 09:47:46,863+0200 INFO (jsonrpc/4) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:46,922+0200 INFO (jsonrpc/3) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:47,011+0200 INFO (jsonrpc/3) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=42268a48-5d3a-4afd-bed2-ba9d50ce3b4c (api:48)
2022-09-06 09:47:47,012+0200 INFO (jsonrpc/3) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.8', 'delay': '0.000717237', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.9', 'delay': '0.000591494', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.1', 'delay': '0.000514856', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.9', 'delay': '0.000298594', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=42268a48-5d3a-4afd-bed2-ba9d50ce3b4c (api:54)
2022-09-06 09:47:47,013+0200 INFO (jsonrpc/3) [vdsm.api] START multipath_health() from=::1,39940, task_id=b317f13e-458e-4211-a4e0-0f84dcfa369a (api:48)
2022-09-06 09:47:47,013+0200 INFO (jsonrpc/3) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=b317f13e-458e-4211-a4e0-0f84dcfa369a (api:54)
2022-09-06 09:47:47,030+0200 INFO (jsonrpc/3) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:47,677+0200 INFO (periodic/0) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:47,678+0200 INFO (periodic/0) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=231.59*, wait=231.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=2660cba6-9eb1-40ae-8ca3-1e6062a3c4d6 (api:48)
2022-09-06 09:47:47,678+0200 INFO (periodic/0) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=2660cba6-9eb1-40ae-8ca3-1e6062a3c4d6 (api:54)
2022-09-06 09:47:49,678+0200 INFO (periodic/2) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:49,679+0200 INFO (periodic/2) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=233.59*, wait=233.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=23d82be4-924f-4864-a984-73a556971963 (api:48)
2022-09-06 09:47:49,679+0200 INFO (periodic/2) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=23d82be4-924f-4864-a984-73a556971963 (api:54)
2022-09-06 09:47:51,498+0200 INFO (jsonrpc/6) [api.virt] START getStats() from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:48)
2022-09-06 09:47:51,499+0200 INFO (jsonrpc/6) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'} (api:129)
2022-09-06 09:47:51,499+0200 INFO (jsonrpc/6) [api.virt] FINISH getStats return={'status': {'code': 1, 'message': "Virtual machine does not exist: {'vmId': '0c418190-42da-42fe-a992-dbb83a364b93'}"}} from=::1,39940, vmId=0c418190-42da-42fe-a992-dbb83a364b93 (api:54)
2022-09-06 09:47:51,499+0200 INFO (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2022-09-06 09:47:52,353+0200 INFO (periodic/1) [vdsm.api] START repoStats(domains=()) from=internal, task_id=a926f3a1-6bc2-4621-882a-b3d15bab115c (api:48)
2022-09-06 09:47:52,355+0200 INFO (periodic/1) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '2.2', 'delay': '0.000597231', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '0.9', 'delay': '0.000591494', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.9', 'delay': '0.000514856', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.3', 'delay': '0.000441944', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=internal, task_id=a926f3a1-6bc2-4621-882a-b3d15bab115c (api:54)
2022-09-06 09:47:52,808+0200 INFO (jsonrpc/7) [api.host] START getAllVmStats() from=::ffff:10.36.191.25,48392 (api:48)
2022-09-06 09:47:52,819+0200 INFO (jsonrpc/7) [api.host] FINISH getAllVmStats return={'status': {'code': 0, 'message': 'Done'}, 'statsList': (suppressed)} from=::ffff:10.36.191.25,48392 (api:54)
2022-09-06 09:47:53,678+0200 INFO (periodic/2) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:53,679+0200 INFO (periodic/2) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=237.59*, wait=237.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=0757f16d-2d73-45fa-abfe-cfbabcb2685f (api:48)
2022-09-06 09:47:53,679+0200 INFO (periodic/2) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=0757f16d-2d73-45fa-abfe-cfbabcb2685f (api:54)
2022-09-06 09:47:55,027+0200 INFO (jsonrpc/1) [api.host] START getStats() from=::ffff:10.36.191.25,48392 (api:48)
2022-09-06 09:47:55,095+0200 INFO (jsonrpc/1) [vdsm.api] START repoStats(domains=()) from=::ffff:10.36.191.25,48392, task_id=af860398-6b22-4c4b-8705-0fc8380fbad7 (api:48)
2022-09-06 09:47:55,096+0200 INFO (jsonrpc/1) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '4.9', 'delay': '0.000597231', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '2.0', 'delay': '0.00063301', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '3.6', 'delay': '0.000514856', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '4.0', 'delay': '0.000441944', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::ffff:10.36.191.25,48392, task_id=af860398-6b22-4c4b-8705-0fc8380fbad7 (api:54)
2022-09-06 09:47:55,096+0200 INFO (jsonrpc/1) [vdsm.api] START multipath_health() from=::ffff:10.36.191.25,48392, task_id=022551e0-9082-404e-b463-3f89930afab6 (api:48)
2022-09-06 09:47:55,097+0200 INFO (jsonrpc/1) [vdsm.api] FINISH multipath_health return={} from=::ffff:10.36.191.25,48392, task_id=022551e0-9082-404e-b463-3f89930afab6 (api:54)
2022-09-06 09:47:55,114+0200 INFO (jsonrpc/1) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::ffff:10.36.191.25,48392 (api:54)
2022-09-06 09:47:55,194+0200 INFO (jsonrpc/3) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=74ccb016-887f-4e74-8e6b-ea7df0f39eb4 (api:48)
2022-09-06 09:47:55,194+0200 INFO (jsonrpc/3) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '5.0', 'delay': '0.000597231', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=74ccb016-887f-4e74-8e6b-ea7df0f39eb4 (api:54)
2022-09-06 09:47:55,678+0200 INFO (periodic/4) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:55,679+0200 INFO (periodic/4) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=239.60*, wait=239.59, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=962ef76f-298a-4517-820d-451be940d5a4 (api:48)
2022-09-06 09:47:55,679+0200 INFO (periodic/4) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=962ef76f-298a-4517-820d-451be940d5a4 (api:54)
2022-09-06 09:47:56,452+0200 INFO (jsonrpc/2) [vdsm.api] START repoStats(domains=['1af18b4e-e197-40e8-a691-7da21d32a6b2']) from=::1,39940, task_id=db0230f1-6b12-4347-9d73-354f33279605 (api:48)
2022-09-06 09:47:56,453+0200 INFO (jsonrpc/2) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.3', 'delay': '0.000597231', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}} from=::1,39940, task_id=db0230f1-6b12-4347-9d73-354f33279605 (api:54)
2022-09-06 09:47:56,934+0200 INFO (jsonrpc/7) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:57,053+0200 INFO (jsonrpc/7) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=e42d1411-b9a3-48e2-a55c-bed281bca310 (api:48)
2022-09-06 09:47:57,055+0200 INFO (jsonrpc/7) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '6.9', 'delay': '0.000597231', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '3.9', 'delay': '0.00063301', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.2', 'delay': '0.000639315', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '1.9', 'delay': '0.000441944', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=e42d1411-b9a3-48e2-a55c-bed281bca310 (api:54)
2022-09-06 09:47:57,056+0200 INFO (jsonrpc/7) [vdsm.api] START multipath_health() from=::1,39940, task_id=47f90871-8289-45fa-ab41-baab064a4d85 (api:48)
2022-09-06 09:47:57,056+0200 INFO (jsonrpc/7) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=47f90871-8289-45fa-ab41-baab064a4d85 (api:54)
2022-09-06 09:47:57,079+0200 INFO (jsonrpc/7) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:57,099+0200 INFO (jsonrpc/1) [api.host] START getStats() from=::1,39940 (api:48)
2022-09-06 09:47:57,202+0200 INFO (jsonrpc/1) [vdsm.api] START repoStats(domains=()) from=::1,39940, task_id=45238f29-0176-4bc2-85b6-df25467c90bd (api:48)
2022-09-06 09:47:57,203+0200 INFO (jsonrpc/1) [vdsm.api] FINISH repoStats return={'1af18b4e-e197-40e8-a691-7da21d32a6b2': {'code': 0, 'lastCheck': '7.0', 'delay': '0.000597231', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, '6cff1d5a-3188-407c-b217-ab33d7b92476': {'code': 0, 'lastCheck': '4.1', 'delay': '0.00063301', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'cf819cb9-a51f-4b7a-baf6-a2a472aae6da': {'code': 0, 'lastCheck': '0.3', 'delay': '0.000639315', 'valid': True, 'version': 5, 'acquired': True, 'actual': True}, 'c59c325a-0b8a-45d9-b03d-b54c258f2ce5': {'code': 0, 'lastCheck': '2.1', 'delay': '0.000441944', 'valid': True, 'version': 0, 'acquired': True, 'actual': True}} from=::1,39940, task_id=45238f29-0176-4bc2-85b6-df25467c90bd (api:54)
2022-09-06 09:47:57,203+0200 INFO (jsonrpc/1) [vdsm.api] START multipath_health() from=::1,39940, task_id=c3d5a123-dfb8-4bd0-b01e-9c4dddde3ff6 (api:48)
2022-09-06 09:47:57,204+0200 INFO (jsonrpc/1) [vdsm.api] FINISH multipath_health return={} from=::1,39940, task_id=c3d5a123-dfb8-4bd0-b01e-9c4dddde3ff6 (api:54)
2022-09-06 09:47:57,217+0200 INFO (jsonrpc/1) [api.host] FINISH getStats return={'status': {'code': 0, 'message': 'Done'}, 'info': (suppressed)} from=::1,39940 (api:54)
2022-09-06 09:47:57,682+0200 INFO (periodic/1) [virt.vm] (vmId='cfff0648-6502-4977-95a8-c6f95c723f6d') Requesting an extension for volume 785958e3-7136-4296-a321-406ac5596e78 on domain 6cff1d5a-3188-407c-b217-ab33d7b92476 block_info BlockInfo(index=12, name='sda', path='/rhev/data-center/mnt/blockSD/6cff1d5a-3188-407c-b217-ab33d7b92476/images/7e574c46-24c7-4de1-81ce-700653d126d6/785958e3-7136-4296-a321-406ac5596e78', allocation=2690318336, capacity=53687091200, physical=2684354560, threshold=0) (thinp:388)
2022-09-06 09:47:57,683+0200 INFO (periodic/1) [vdsm.api] START sendExtendMsg(spUUID='a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', volDict={'domainID': '6cff1d5a-3188-407c-b217-ab33d7b92476', 'imageID': '7e574c46-24c7-4de1-81ce-700653d126d6', 'internal': False, 'name': 'sda', 'newSize': 5368709120, 'poolID': 'a6ecdb7b-f2d0-44e1-856a-2cf1be90d7bf', 'volumeID': '785958e3-7136-4296-a321-406ac5596e78', 'clock': <Clock(total=241.60*, wait=241.60, extend-volume=0.00*)>, 'callback': None}, newSize=5368709120, callbackFunc=<bound method VolumeMonitor._extend_volume_completed of <vdsm.virt.thinp.VolumeMonitor object at 0x7fa8f406ca58>>) from=internal, task_id=f9570262-013b-40d8-b641-100d97e772ec (api:48)
2022-09-06 09:47:57,684+0200 INFO (periodic/1) [vdsm.api] FINISH sendExtendMsg return=None from=internal, task_id=f9570262-013b-40d8-b641-100d97e772ec (api:54)
_______________________________________________
Users mailing list -- users@ovirt.org
To unsubscribe send an email to users-le...@ovirt.org
Privacy Statement: https://www.ovirt.org/privacy-policy.html
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/TKZKNUZDFT7FX3Z6HJVN2DEEKOYQUEH6/
