During the VM's migrations from one host to another, various unrelated hosts have
timeouts and some of them are being restarted by Engine due to their
"unresponsive" status. However they're working fine at that time... It only
happens when migration process is being run on other unrelated hosts.
Of course, one solution might be increasing the timeout, but it's only a workaround
and in my opinion, not a proper solution.
This whole problem occurs after few minutes of when the migrations were started.
oVirt-engine version: 4.4.10.7 (at the moment we do not have the available window for an
update)
vdsm version on hosts: 4.40.100.2
** Below logs are example of one of many hosts as all of them had similar messages **
Engine logs when first timeout appeared until it's restarted:
09:31:07,856+01 INFO [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor) [] No interaction with host 'os-host06' for 20000 ms.
09:31:29,242+01 ERROR [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor) [] Connection timeout for host 'os-host06', last response arrived 41571
ms ago.
09:31:29,243+01 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-25) [] Command
'GetAllVmStatsVDSCommand(HostName = os-host06,
VdsIdVDSCommandParametersBase:{hostId='aa11wa4d-6e20-44hf-a76e-b0878bba1f42'})'
execution failed: VDSGenericException: VDSNetworkException: Connection timeout for host
'os-host06', last response arrived 41571 ms ago.
09:31:29,243+01 INFO [org.ovirt.engine.core.vdsbroker.monitoring.PollVmStatsRefresher]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-25) [] Failed to
fetch vms info for host 'os-host06'(aa11wa4d-6e20-44hf-a76e-b0878bba1f42) -
skipping VMs monitoring.
09:31:29,246+01 INFO [org.ovirt.engine.core.vdsbroker.VdsManager]
(EE-ManagedThreadFactory-engine-Thread-3) [] Clearing domains data for host os-host06
09:31:29,251+01 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-95) [] EVENT_ID:
VDS_BROKER_COMMAND_FAILURE(10,802), VDSM os-host06 command Get Host Statistics failed:
Connection timeout for host 'os-host06', last response arrived 41571 ms ago.
09:31:29,251+01 ERROR [org.ovirt.engine.core.vdsbroker.monitoring.HostMonitoring]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-95) [] Unable to
GetStats: VDSNetworkException: VDSGenericException: VDSNetworkException: Connection
timeout for host 'os-host06', last response arrived 41571 ms ago.
09:31:29,287+01 INFO [org.ovirt.engine.core.vdsbroker.VdsManager]
(EE-ManagedThreadFactory-engine-Thread-3) [] Server failed to respond,
vds_id='aa11wa4d-6e20-44hf-a76e-b0878bba1f42', vds_name='os-host06',
vm_count=8, spm_status='None', non-responsive_timeout (seconds)=64, error:
VDSGenericException: VDSNetworkException: Connection timeout for host 'os-host06',
last response arrived 41571 ms ago.
09:31:29,289+01 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(EE-ManagedThreadFactory-engine-Thread-3) [] EVENT_ID: VDS_FAILURE(12), Host os-host06 is
non responsive.
09:31:29,551+01 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(EE-ManagedThreadFactory-engine-Thread-38) [2ae04e58] EVENT_ID:
FENCE_OPERATION_USING_AGENT_AND_PROXY_STARTED(9,020), Executing power management status on
Host os-host06 using Proxy Host os-host03 and Fence Agent ipmilan:os-host06-iDrac.
09:31:29,659+01 INFO [org.ovirt.engine.core.bll.pm.SshSoftFencingCommand]
(EE-ManagedThreadFactory-engine-Thread-38) [2ae04e58] Opening SSH Soft Fencing session on
host 'os-host06'
09:31:29,843+01 INFO [org.ovirt.engine.core.bll.pm.SshSoftFencingCommand]
(EE-ManagedThreadFactory-engine-Thread-38) [2ae04e58] Executing SSH Soft Fencing command
on host 'os-host06'
09:31:32,239+01 INFO [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor) [] Connecting to os-host06/10.10.5.17
09:31:44,358+01 INFO [org.ovirt.engine.core.bll.pm.StopVdsCommand]
(EE-ManagedThreadFactory-engine-Thread-38) [2e93a767] Power-Management: STOP of host
'os-host06' initiated.
Logs from host at the same time just before the restart:
09:30:36,926+0100 INFO (periodic/3) [vdsm.api] FINISH getVolumeSize
return={'apparentsize': '1207959552', 'truesize':
'1207959552'} from=internal, task_id=f3f073de-2c08-47b2-aae2-017a7480db61
(api:54)
09:30:39,117+0100 INFO (jsonrpc/3) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:48)
09:30:39,119+0100 INFO (jsonrpc/3) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:54)
09:30:39,123+0100 INFO (jsonrpc/2) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:48)
09:30:39,125+0100 INFO (jsonrpc/2) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:54)
09:30:39,130+0100 INFO (jsonrpc/1) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:48)
09:30:39,131+0100 INFO (jsonrpc/1) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:54)
09:30:39,136+0100 INFO (jsonrpc/4) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:48)
09:30:39,138+0100 INFO (jsonrpc/4) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:54)
09:30:39,143+0100 INFO (jsonrpc/3) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:48)
09:30:39,144+0100 INFO (jsonrpc/3) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:54)
09:30:39,149+0100 INFO (jsonrpc/2) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:48)
09:30:39,151+0100 INFO (jsonrpc/2) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:54)
09:30:39,156+0100 INFO (jsonrpc/1) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:48)
09:30:39,158+0100 INFO (jsonrpc/1) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:54)
09:30:39,162+0100 INFO (jsonrpc/4) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:48)
09:30:39,164+0100 INFO (jsonrpc/4) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:54)
09:30:39,858+0100 INFO (jsonrpc/0) [api.host] START getAllVmStats() from=::1,36652
(api:48)
09:30:39,863+0100 INFO (jsonrpc/0) [api.host] FINISH getAllVmStats
return={'status': {'code': 0, 'message': 'Done'},
'statsList': (suppressed)} from=::1,36652 (api:54)
09:30:39,873+0100 INFO (jsonrpc/3) [api.host] START getAllVmIoTunePolicies()
from=::1,36652 (api:48)
09:30:39,874+0100 INFO (jsonrpc/3) [api.host] FINISH getAllVmIoTunePolicies
return={'status': {'code': 0, 'message': 'Done'},...
09:30:41,228+0100 INFO (jsonrpc/6) [api.host] START getStats()
from=::ffff:10.10.3.150,59772 (api:48)
09:30:41,249+0100 INFO (jsonrpc/6) [vdsm.api] START repoStats(domains=())
from=::ffff:10.10.3.150,59772, task_id=978cd75b-fb99-47ee-af62-0bc0338fc66a (api:48)
09:30:41,250+0100 INFO (jsonrpc/6) [vdsm.api] FINISH repoStats
return={'d178ad4b-37f9-40a3-81b3-826e30900d42': {'code': 0,
'lastCheck': '0.7', 'delay': '0.000389989',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '8f2febd6-b864-4753-9d5a-4f050a0506a7': {'code': 0,
'lastCheck': '0.7', 'delay': '0.000117308',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, 'e54b09c8-e9e3-4c31-93ce-ca84c65045b1': {'code': 0,
'lastCheck': '0.7', 'delay': '0.000123364',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '578d6e98-a849-4c86-a094-459152af0997': {'code': 0,
'lastCheck': '0.7', 'delay': '0.000135331',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '23a31eca-4a47-4f4d-a0df-2edf8fe89f85': {'code': 0,
'lastCheck': '2.1', 'delay': '0.000147366',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}} from=::ffff:10.10.3.150,59772, task_id=978cd75b-fb99-47ee-af62-0bc0338fc66a
(api:54)
09:30:41,250+0100 INFO (jsonrpc/6) [vdsm.api] START multipath_health()
from=::ffff:10.10.3.150,59772, task_id=691b59a6-4a16-4e8d-9676-f1d46a3981b9 (api:48)
09:30:41,250+0100 INFO (jsonrpc/6) [vdsm.api] FINISH multipath_health return={}
from=::ffff:10.10.3.150,59772, task_id=691b59a6-4a16-4e8d-9676-f1d46a3981b9 (api:54)
09:30:41,254+0100 INFO (jsonrpc/6) [api.host] FINISH getStats return={'status':
{'code': 0, 'message': 'Done'}, 'info': (suppressed)}
from=::ffff:10.10.3.150,59772 (api:54)
09:30:48,833+0100 INFO (periodic/0) [vdsm.api] START repoStats(domains=()) from=internal,
task_id=5bdca038-eb0c-4e50-aeca-be2349387a36 (api:48)
09:30:48,833+0100 INFO (periodic/0) [vdsm.api] FINISH repoStats
return={'d178ad4b-37f9-40a3-81b3-826e30900d42': {'code': 0,
'lastCheck': '8.3', 'delay': '0.000389989',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '8f2febd6-b864-4753-9d5a-4f050a0506a7': {'code': 0,
'lastCheck': '8.3', 'delay': '0.000117308',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, 'e54b09c8-e9e3-4c31-93ce-ca84c65045b1': {'code': 0,
'lastCheck': '8.3', 'delay': '0.000123364',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '578d6e98-a849-4c86-a094-459152af0997': {'code': 0,
'lastCheck': '8.3', 'delay': '0.000135331',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '23a31eca-4a47-4f4d-a0df-2edf8fe89f85': {'code': 0,
'lastCheck': '9.7', 'delay': '0.000147366',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}} from=internal, task_id=5bdca038-eb0c-4e50-aeca-be2349387a36 (api:54)
09:30:54,237+0100 INFO (jsonrpc/7) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:48)
09:30:54,239+0100 INFO (jsonrpc/7) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:54)
09:30:54,243+0100 INFO (jsonrpc/5) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:48)
09:30:54,245+0100 INFO (jsonrpc/5) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:54)
09:30:54,250+0100 INFO (jsonrpc/0) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:48)
09:30:54,252+0100 INFO (jsonrpc/0) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:54)
09:30:54,256+0100 INFO (jsonrpc/6) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:48)
09:30:54,258+0100 INFO (jsonrpc/6) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:54)
09:30:54,263+0100 INFO (jsonrpc/7) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:48)
09:30:54,264+0100 INFO (jsonrpc/7) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:54)
09:30:54,269+0100 INFO (jsonrpc/5) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:48)
09:30:54,271+0100 INFO (jsonrpc/5) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:54)
09:30:54,276+0100 INFO (jsonrpc/0) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:48)
09:30:54,278+0100 INFO (jsonrpc/0) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:54)
09:30:54,282+0100 INFO (jsonrpc/6) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:48)
09:30:54,284+0100 INFO (jsonrpc/6) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:54)
09:30:54,888+0100 INFO (jsonrpc/2) [api.host] START getAllVmStats() from=::1,36652
(api:48)
09:30:54,892+0100 INFO (jsonrpc/2) [api.host] FINISH getAllVmStats
return={'status': {'code': 0, 'message': 'Done'},
'statsList': (suppressed)} from=::1,36652 (api:54)
09:30:54,896+0100 INFO (jsonrpc/7) [api.host] START getAllVmIoTunePolicies()
from=::1,36652 (api:48)
09:30:54,896+0100 INFO (jsonrpc/7) [api.host] FINISH getAllVmIoTunePolicies
return={'status': {'code': 0, 'message': 'Done'},....
09:30:55,220+0100 INFO (jsonrpc/1) [api.host] START getAllVmStats()
from=::ffff:10.10.3.150,59772 (api:48)
09:30:55,223+0100 INFO (jsonrpc/1) [throttled] Current getAllVmStats:
{'26157351-db69-4e59-a460-1de23cf47517': 'Up',
'f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6': 'Up',
'f335c1e8-4699-4e81-be22-dcb92a6a3ca6': 'Up',
'50221e76-d8ee-414b-a3b7-f8a860b21831': 'Up',
'25aee386-e8ba-4ac0-85c5-cde2e0d22348': 'Up',
'1348d3e0-c02c-4c9a-b669-601e6dcc9b80': 'Up',
'bdeb4e6f-9546-438a-95c8-70c426c3490c': 'Up',
'01ff01e5-5360-4549-b538-38529537a587': 'Up'} (throttledlog:104)
09:30:55,223+0100 INFO (jsonrpc/1) [api.host] FINISH getAllVmStats
return={'status': {'code': 0, 'message': 'Done'},
'statsList': (suppressed)} from=::ffff:10.10.3.150,59772 (api:54)
09:31:02,775+0100 INFO (jsonrpc/5) [api.host] START getStats()
from=::ffff:10.10.3.150,59772 (api:48)
09:31:02,795+0100 INFO (jsonrpc/5) [vdsm.api] START repoStats(domains=())
from=::ffff:10.10.3.150,59772, task_id=fb00b06c-bd84-450f-91eb-e0e21ce44db9 (api:48)
09:31:02,796+0100 INFO (jsonrpc/5) [vdsm.api] FINISH repoStats
return={'d178ad4b-37f9-40a3-81b3-826e30900d42': {'code': 0,
'lastCheck': '2.2', 'delay': '9.6718e-05',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '8f2febd6-b864-4753-9d5a-4f050a0506a7': {'code': 0,
'lastCheck': '2.2', 'delay': '0.000106966',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, 'e54b09c8-e9e3-4c31-93ce-ca84c65045b1': {'code': 0,
'lastCheck': '2.3', 'delay': '0.000106646',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '578d6e98-a849-4c86-a094-459152af0997': {'code': 0,
'lastCheck': '2.3', 'delay': '0.000113708',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '23a31eca-4a47-4f4d-a0df-2edf8fe89f85': {'code': 0,
'lastCheck': '3.6', 'delay': '0.000144113',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}} from=::ffff:10.10.3.150,59772, task_id=fb00b06c-bd84-450f-91eb-e0e21ce44db9
(api:54)
09:31:02,796+0100 INFO (jsonrpc/5) [vdsm.api] START multipath_health()
from=::ffff:10.10.3.150,59772, task_id=0edc02f9-41e9-430a-97f9-135ba36e8941 (api:48)
09:31:02,796+0100 INFO (jsonrpc/5) [vdsm.api] FINISH multipath_health return={}
from=::ffff:10.10.3.150,59772, task_id=0edc02f9-41e9-430a-97f9-135ba36e8941 (api:54)
09:31:02,801+0100 INFO (jsonrpc/5) [api.host] FINISH getStats return={'status':
{'code': 0, 'message': 'Done'}, 'info': (suppressed)}
from=::ffff:10.10.3.150,59772 (api:54)
09:31:03,859+0100 INFO (periodic/3) [vdsm.api] START repoStats(domains=()) from=internal,
task_id=5f40ee63-140d-416d-bc5f-dd3b696c1d10 (api:48)
09:31:03,859+0100 INFO (periodic/3) [vdsm.api] FINISH repoStats
return={'d178ad4b-37f9-40a3-81b3-826e30900d42': {'code': 0,
'lastCheck': '3.3', 'delay': '9.6718e-05',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '8f2febd6-b864-4753-9d5a-4f050a0506a7': {'code': 0,
'lastCheck': '3.3', 'delay': '0.000106966',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, 'e54b09c8-e9e3-4c31-93ce-ca84c65045b1': {'code': 0,
'lastCheck': '3.3', 'delay': '0.000106646',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '578d6e98-a849-4c86-a094-459152af0997': {'code': 0,
'lastCheck': '3.4', 'delay': '0.000113708',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '23a31eca-4a47-4f4d-a0df-2edf8fe89f85': {'code': 0,
'lastCheck': '4.6', 'delay': '0.000144113',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}} from=internal, task_id=5f40ee63-140d-416d-bc5f-dd3b696c1d10 (api:54)
09:31:09,351+0100 INFO (jsonrpc/0) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:48)
09:31:09,353+0100 INFO (jsonrpc/0) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:54)
09:31:09,358+0100 INFO (jsonrpc/6) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:48)
09:31:09,360+0100 INFO (jsonrpc/6) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:54)
09:31:09,365+0100 INFO (jsonrpc/7) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:48)
09:31:09,366+0100 INFO (jsonrpc/7) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:54)
09:31:09,371+0100 INFO (jsonrpc/5) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:48)
09:31:09,373+0100 INFO (jsonrpc/5) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:54)
09:31:09,378+0100 INFO (jsonrpc/0) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:48)
09:31:09,379+0100 INFO (jsonrpc/0) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:54)
09:31:09,384+0100 INFO (jsonrpc/6) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:48)
09:31:09,386+0100 INFO (jsonrpc/6) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:54)
09:31:09,391+0100 INFO (jsonrpc/7) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:48)
09:31:09,392+0100 INFO (jsonrpc/7) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:54)
09:31:09,397+0100 INFO (jsonrpc/5) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:48)
09:31:09,398+0100 INFO (jsonrpc/5) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:54)
09:31:09,911+0100 INFO (jsonrpc/4) [api.host] START getAllVmStats() from=::1,36652
(api:48)
09:31:09,915+0100 INFO (jsonrpc/4) [api.host] FINISH getAllVmStats
return={'status': {'code': 0, 'message': 'Done'},
'statsList': (suppressed)} from=::1,36652 (api:54)
09:31:09,919+0100 INFO (jsonrpc/0) [api.host] START getAllVmIoTunePolicies()
from=::1,36652 (api:48)
09:31:09,919+0100 INFO (jsonrpc/0) [api.host] FINISH getAllVmIoTunePolicies
return={'status': {'code': 0, 'message': 'Done'},...
09:30:55,220+0100 INFO (jsonrpc/1) [api.host] START getAllVmStats()
from=::ffff:10.10.3.150,59772 (api:48)
09:30:55,223+0100 INFO (jsonrpc/1) [throttled] Current getAllVmStats:
{'26157351-db69-4e59-a460-1de23cf47517': 'Up',
'f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6': 'Up',
'f335c1e8-4699-4e81-be22-dcb92a6a3ca6': 'Up',
'50221e76-d8ee-414b-a3b7-f8a860b21831': 'Up',
'25aee386-e8ba-4ac0-85c5-cde2e0d22348': 'Up',
'1348d3e0-c02c-4c9a-b669-601e6dcc9b80': 'Up',
'bdeb4e6f-9546-438a-95c8-70c426c3490c': 'Up',
'01ff01e5-5360-4549-b538-38529537a587': 'Up'} (throttledlog:104)
09:30:55,223+0100 INFO (jsonrpc/1) [api.host] FINISH getAllVmStats
return={'status': {'code': 0, 'message': 'Done'},
'statsList': (suppressed)} from=::ffff:10.10.3.150,59772 (api:54)
09:31:02,775+0100 INFO (jsonrpc/5) [api.host] START getStats()
from=::ffff:10.10.3.150,59772 (api:48)
09:31:02,795+0100 INFO (jsonrpc/5) [vdsm.api] START repoStats(domains=())
from=::ffff:10.10.3.150,59772, task_id=fb00b06c-bd84-450f-91eb-e0e21ce44db9 (api:48)
09:31:02,796+0100 INFO (jsonrpc/5) [vdsm.api] FINISH repoStats
return={'d178ad4b-37f9-40a3-81b3-826e30900d42': {'code': 0,
'lastCheck': '2.2', 'delay': '9.6718e-05',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '8f2febd6-b864-4753-9d5a-4f050a0506a7': {'code': 0,
'lastCheck': '2.2', 'delay': '0.000106966',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, 'e54b09c8-e9e3-4c31-93ce-ca84c65045b1': {'code': 0,
'lastCheck': '2.3', 'delay': '0.000106646',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '578d6e98-a849-4c86-a094-459152af0997': {'code': 0,
'lastCheck': '2.3', 'delay': '0.000113708',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '23a31eca-4a47-4f4d-a0df-2edf8fe89f85': {'code': 0,
'lastCheck': '3.6', 'delay': '0.000144113',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}} from=::ffff:10.10.3.150,59772, task_id=fb00b06c-bd84-450f-91eb-e0e21ce44db9
(api:54)
09:31:02,796+0100 INFO (jsonrpc/5) [vdsm.api] START multipath_health()
from=::ffff:10.10.3.150,59772, task_id=0edc02f9-41e9-430a-97f9-135ba36e8941 (api:48)
09:31:02,796+0100 INFO (jsonrpc/5) [vdsm.api] FINISH multipath_health return={}
from=::ffff:10.10.3.150,59772, task_id=0edc02f9-41e9-430a-97f9-135ba36e8941 (api:54)
09:31:02,801+0100 INFO (jsonrpc/5) [api.host] FINISH getStats return={'status':
{'code': 0, 'message': 'Done'}, 'info': (suppressed)}
from=::ffff:10.10.3.150,59772 (api:54)
09:31:03,859+0100 INFO (periodic/3) [vdsm.api] START repoStats(domains=()) from=internal,
task_id=5f40ee63-140d-416d-bc5f-dd3b696c1d10 (api:48)
09:31:03,859+0100 INFO (periodic/3) [vdsm.api] FINISH repoStats
return={'d178ad4b-37f9-40a3-81b3-826e30900d42': {'code': 0,
'lastCheck': '3.3', 'delay': '9.6718e-05',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '8f2febd6-b864-4753-9d5a-4f050a0506a7': {'code': 0,
'lastCheck': '3.3', 'delay': '0.000106966',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, 'e54b09c8-e9e3-4c31-93ce-ca84c65045b1': {'code': 0,
'lastCheck': '3.3', 'delay': '0.000106646',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '578d6e98-a849-4c86-a094-459152af0997': {'code': 0,
'lastCheck': '3.4', 'delay': '0.000113708',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '23a31eca-4a47-4f4d-a0df-2edf8fe89f85': {'code': 0,
'lastCheck': '4.6', 'delay': '0.000144113',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}} from=internal, task_id=5f40ee63-140d-416d-bc5f-dd3b696c1d10 (api:54)
09:31:09,351+0100 INFO (jsonrpc/0) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:48)
09:31:09,353+0100 INFO (jsonrpc/0) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:54)
09:31:09,358+0100 INFO (jsonrpc/6) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:48)
09:31:09,360+0100 INFO (jsonrpc/6) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:54)
09:31:09,365+0100 INFO (jsonrpc/7) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:48)
09:31:09,366+0100 INFO (jsonrpc/7) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:54)
09:31:09,371+0100 INFO (jsonrpc/5) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:48)
09:31:09,373+0100 INFO (jsonrpc/5) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:54)
09:31:09,378+0100 INFO (jsonrpc/0) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:48)
09:31:09,379+0100 INFO (jsonrpc/0) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:54)
09:31:09,384+0100 INFO (jsonrpc/6) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:48)
09:31:09,386+0100 INFO (jsonrpc/6) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:54)
09:31:09,391+0100 INFO (jsonrpc/7) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:48)
09:31:09,392+0100 INFO (jsonrpc/7) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:54)
09:31:09,397+0100 INFO (jsonrpc/5) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:48)
09:31:09,398+0100 INFO (jsonrpc/5) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:54)
09:31:09,911+0100 INFO (jsonrpc/4) [api.host] START getAllVmStats() from=::1,36652
(api:48)
09:31:09,915+0100 INFO (jsonrpc/4) [api.host] FINISH getAllVmStats
return={'status': {'code': 0, 'message': 'Done'},
'statsList': (suppressed)} from=::1,36652 (api:54)
09:31:09,919+0100 INFO (jsonrpc/0) [api.host] START getAllVmIoTunePolicies()
from=::1,36652 (api:48)
09:31:09,919+0100 INFO (jsonrpc/0) [api.host] FINISH getAllVmIoTunePolicies
return={'status': {'code': 0, 'message': 'Done'},...
09:31:18,887+0100 INFO (periodic/1) [vdsm.api] START repoStats(domains=()) from=internal,
task_id=cd897cf9-6f3e-4514-92cf-9a9939f7ce52 (api:48)
09:31:18,887+0100 INFO (periodic/1) [vdsm.api] FINISH repoStats
return={'d178ad4b-37f9-40a3-81b3-826e30900d42': {'code': 0,
'lastCheck': '8.3', 'delay': '0.000106409',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '8f2febd6-b864-4753-9d5a-4f050a0506a7': {'code': 0,
'lastCheck': '8.4', 'delay': '0.000115832',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, 'e54b09c8-e9e3-4c31-93ce-ca84c65045b1': {'code': 0,
'lastCheck': '8.4', 'delay': '0.00011779',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '578d6e98-a849-4c86-a094-459152af0997': {'code': 0,
'lastCheck': '8.4', 'delay': '0.000125551',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}, '23a31eca-4a47-4f4d-a0df-2edf8fe89f85': {'code': 0,
'lastCheck': '9.7', 'delay': '0.000130676',
'valid': True, 'version': 5, 'acquired': True, 'actual':
True}} from=internal, task_id=cd897cf9-6f3e-4514-92cf-9a9939f7ce52 (api:54)
09:31:24,466+0100 INFO (jsonrpc/6) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:48)
09:31:24,468+0100 INFO (jsonrpc/6) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=26157351-db69-4e59-a460-1de23cf47517 (api:54)
09:31:24,473+0100 INFO (jsonrpc/7) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:48)
09:31:24,474+0100 INFO (jsonrpc/7) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f68f945c-8441-4ba7-ad7c-3ed3cc4efbe6 (api:54)
09:31:24,479+0100 INFO (jsonrpc/5) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:48)
09:31:24,481+0100 INFO (jsonrpc/5) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=f335c1e8-4699-4e81-be22-dcb92a6a3ca6 (api:54)
09:31:24,486+0100 INFO (jsonrpc/0) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:48)
09:31:24,487+0100 INFO (jsonrpc/0) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=25aee386-e8ba-4ac0-85c5-cde2e0d22348 (api:54)
09:31:24,492+0100 INFO (jsonrpc/6) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:48)
09:31:24,494+0100 INFO (jsonrpc/6) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=1348d3e0-c02c-4c9a-b669-601e6dcc9b80 (api:54)
09:31:24,499+0100 INFO (jsonrpc/7) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:48)
09:31:24,501+0100 INFO (jsonrpc/7) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=bdeb4e6f-9546-438a-95c8-70c426c3490c (api:54)
09:31:24,505+0100 INFO (jsonrpc/5) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:48)
09:31:24,507+0100 INFO (jsonrpc/5) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=50221e76-d8ee-414b-a3b7-f8a860b21831 (api:54)
09:31:24,512+0100 INFO (jsonrpc/0) [api.virt] START setCpuTunePeriod(period=100000)
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:48)
09:31:24,513+0100 INFO (jsonrpc/0) [api.virt] FINISH setCpuTunePeriod
return={'status': {'code': 0, 'message': 'Done'}}
from=::1,36652, vmId=01ff01e5-5360-4549-b538-38529537a587 (api:54)
09:31:24,925+0100 INFO (jsonrpc/3) [api.host] START getAllVmStats() from=::1,36652
(api:48)
09:31:24,929+0100 INFO (jsonrpc/3) [api.host] FINISH getAllVmStats
return={'status': {'code': 0, 'message': 'Done'},
'statsList': (suppressed)} from=::1,36652 (api:54)
09:31:24,933+0100 INFO (jsonrpc/6) [api.host] START getAllVmIoTunePolicies()
from=::1,36652 (api:48)
09:31:24,933+0100 INFO (jsonrpc/6) [api.host] FINISH getAllVmIoTunePolicies
return={'status': {'code': 0, 'message': 'Done'},...