Attachment 1456268 Details for Bug 1596619 – VDSM log

VDSM log

1596619_vdsm.log (text/plain), 97.78 KB, created by matthias.leopold on 2018-07-03 15:28:46 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: matthias.leopold

Created: 2018-07-03 15:28:46 UTC

Size: 97.78 KB

patch

obsolete

>2018-07-03 16:31:00,377+0200 DEBUG (qgapoller/1) [vds] Calling QEMU-GA command for vm_id='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f', command: {"execute": "guest-info"} (qemuguestagent:201)
>2018-07-03 16:31:00,378+0200 DEBUG (qgapoller/1) [vds] Call returned: '{"return":{"version":"2.8.0","supported_commands":[{"enabled":true,"name":"guest-sync-delimited","success-response":true},{"enabled":true,"name":"guest-sync","success-response":true},{"enabled":true,"name":"guest-suspend-ram","success-response":false},{"enabled":true,"name":"guest-suspend-hybrid","success-response":false},{"enabled":true,"name":"guest-suspend-disk","success-response":false},{"enabled":true,"name":"guest-shutdown","success-response":false},{"enabled":true,"name":"guest-set-vcpus","success-response":true},{"enabled":true,"name":"guest-set-user-password","success-response":true},{"enabled":true,"name":"guest-set-time","success-response":true},{"enabled":true,"name":"guest-set-memory-blocks","success-response":true},{"enabled":true,"name":"guest-ping","success-response":true},{"enabled":true,"name":"guest-network-get-interfaces","success-response":true},{"enabled":true,"name":"guest-info","success-response":true},{"enabled":true,"name":"guest-get-vcpus","success-response":true},{"enabled":true,"name":"guest-get-time","success-response":true},{"enabled":true,"name":"guest-get-memory-blocks","success-response":true},{"enabled":true,"name":"guest-get-memory-block-info","success-response":true},{"enabled":true,"name":"guest-get-fsinfo","success-response":true},{"enabled":true,"name":"guest-fstrim","success-response":true},{"enabled":true,"name":"guest-fsfreeze-thaw","success-response":true},{"enabled":true,"name":"guest-fsfreeze-status","success-response":true},{"enabled":true,"name":"guest-fsfreeze-freeze-list","success-response":true},{"enabled":true,"name":"guest-fsfreeze-freeze","success-response":true},{"enabled":false,"name":"guest-file-write","success-response":true},{"enabled":false,"name":"guest-file-seek","success-response":true},{"enabled":false,"name":"guest-file-read","success-response":true},{"enabled":false,"name":"guest-file-open","success-response":true},{"enabled":false,"name":"guest-file-flush","success-response":true},{"enabled":false,"name":"guest-file-close","success-response":true},{"enabled":false,"name":"guest-exec-status","success-response":true},{"enabled":false,"name":"guest-exec","success-response":true}]}}' (qemuguestagent:204)
>2018-07-03 16:31:00,378+0200 DEBUG (qgapoller/1) [vds] QEMU-GA caps (vm_id=4a8c9902-f9ab-490f-b1dd-82d9aee63b5f): {'commands': set([u'guest-suspend-hybrid', u'guest-get-fsinfo', u'guest-set-time', u'guest-get-memory-block-info', u'guest-sync-delimited', u'guest-network-get-interfaces', u'guest-fstrim', u'guest-set-user-password', u'guest-shutdown', u'guest-get-vcpus', u'guest-fsfreeze-freeze', u'guest-sync', u'guest-set-memory-blocks', u'guest-fsfreeze-status', u'guest-ping', u'guest-fsfreeze-freeze-list', u'guest-info', u'guest-get-memory-blocks', u'guest-set-vcpus', u'guest-fsfreeze-thaw', u'guest-suspend-disk', u'guest-get-time', u'guest-suspend-ram']), 'version': u'2.8.0'} (qemuguestagent:320)
>2018-07-03 16:31:00,895+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674676, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 1155, u'mem_total': 1814656, u'mem_unused': 1506828}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:01,828+0200 INFO  (periodic/0) [vdsm.api] START getVolumeSize(sdUUID='ce86cad9-67d2-44e2-b4ab-f445f856e274', spUUID='1285d24b-53d1-4b4d-bba4-4aa6264f0c4a', imgUUID='e79b23b7-03fe-42f2-af61-8dba1d9e9d01', volUUID='11dd6e3b-6621-4cc3-949d-77eea64f6444', options=None) from=internal, task_id=c61459b7-e4a8-4bdc-9649-90453d01af3b (api:46)
>2018-07-03 16:31:01,828+0200 INFO  (periodic/0) [vdsm.api] FINISH getVolumeSize return={'truesize': '9529458688', 'apparentsize': '9529458688'} from=internal, task_id=c61459b7-e4a8-4bdc-9649-90453d01af3b (api:52)
>2018-07-03 16:31:01,828+0200 INFO  (periodic/0) [vdsm.api] START getVolumeSize(sdUUID='ce86cad9-67d2-44e2-b4ab-f445f856e274', spUUID='1285d24b-53d1-4b4d-bba4-4aa6264f0c4a', imgUUID='7d8b4f11-9f6a-490c-b847-a4b9f7a70c31', volUUID='4c27d800-b040-4616-b2d5-e07a2476d51e', options=None) from=internal, task_id=d0605692-5b02-47b6-8fa2-18e5e17207f5 (api:46)
>2018-07-03 16:31:01,828+0200 INFO  (periodic/0) [vdsm.api] FINISH getVolumeSize return={'truesize': '3221225472', 'apparentsize': '3221225472'} from=internal, task_id=d0605692-5b02-47b6-8fa2-18e5e17207f5 (api:52)
>2018-07-03 16:31:02,025+0200 DEBUG (jsonrpc/6) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:02,025+0200 INFO  (jsonrpc/6) [api.host] START getAllVmStats() from=::ffff:xxx.yyy.215.6,41368 (api:46)
>2018-07-03 16:31:02,026+0200 INFO  (jsonrpc/6) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::ffff:xxx.yyy.215.6,41368 (api:52)
>2018-07-03 16:31:02,026+0200 DEBUG (jsonrpc/6) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmStats' in bridge with (suppressed) (__init__:617)
>2018-07-03 16:31:02,026+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:04,579+0200 DEBUG (jsonrpc/2) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:04,580+0200 INFO  (jsonrpc/2) [api.host] START getAllVmStats() from=::1,48366 (api:46)
>2018-07-03 16:31:04,581+0200 INFO  (jsonrpc/2) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::1,48366 (api:52)
>2018-07-03 16:31:04,581+0200 DEBUG (jsonrpc/2) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmStats' in bridge with (suppressed) (__init__:617)
>2018-07-03 16:31:04,581+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:04,610+0200 DEBUG (jsonrpc/7) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmIoTunePolicies' in bridge with {} (__init__:590)
>2018-07-03 16:31:04,610+0200 INFO  (jsonrpc/7) [api.host] START getAllVmIoTunePolicies() from=::1,48366 (api:46)
>2018-07-03 16:31:04,611+0200 INFO  (jsonrpc/7) [api.host] FINISH getAllVmIoTunePolicies return={'status': {'message': 'Done', 'code': 0}, 'io_tune_policies_dict': {'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f': {'policy': [], 'current_values': [{'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/e79b23b7-03fe-42f2-af61-8dba1d9e9d01/11dd6e3b-6621-4cc3-949d-77eea64f6444', 'name': 'sda'}, {'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/7d8b4f11-9f6a-490c-b847-a4b9f7a70c31/4c27d800-b040-4616-b2d5-e07a2476d51e', 'name': 'sdc'}]}}} from=::1,48366 (api:52)
>2018-07-03 16:31:04,611+0200 DEBUG (jsonrpc/7) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmIoTunePolicies' in bridge with {'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f': {'policy': [], 'current_values': [{'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/e79b23b7-03fe-42f2-af61-8dba1d9e9d01/11dd6e3b-6621-4cc3-949d-77eea64f6444', 'name': 'sda'}, {'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/7d8b4f11-9f6a-490c-b847-a4b9f7a70c31/4c27d800-b040-4616-b2d5-e07a2476d51e', 'name': 'sdc'}]}} (__init__:617)
>2018-07-03 16:31:04,611+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:04,621+0200 INFO  (periodic/0) [vdsm.api] START repoStats(domains=()) from=internal, task_id=7b05af3e-b157-473a-97cf-cfb48643bdb1 (api:46)
>2018-07-03 16:31:04,621+0200 INFO  (periodic/0) [vdsm.api] FINISH repoStats return={u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000154653', 'lastCheck': '0.5', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000264589', 'lastCheck': '0.6', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000174867', 'lastCheck': '0.5', 'valid': True}} from=internal, task_id=7b05af3e-b157-473a-97cf-cfb48643bdb1 (api:52)
>2018-07-03 16:31:04,621+0200 INFO  (periodic/0) [vdsm.api] START multipath_health() from=internal, task_id=3c50907c-6f08-4a3a-8046-964f44c7567c (api:46)
>2018-07-03 16:31:04,621+0200 INFO  (periodic/0) [vdsm.api] FINISH multipath_health return={} from=internal, task_id=3c50907c-6f08-4a3a-8046-964f44c7567c (api:52)
>2018-07-03 16:31:05,902+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674676, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 2, u'mem_total': 1814656, u'mem_unused': 1506828}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:06,075+0200 DEBUG (periodic/3) [virt.sampling.VMBulkstatsMonitor] sampled timestamp 4654899.62 elapsed 0.000 acquired True domains all (sampling:522)
>2018-07-03 16:31:09,302+0200 DEBUG (qgapoller/0) [vds] Not sending QEMU-GA command 'guest-get-users' to vm_id='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f', command is not supported (qemuguestagent:191)
>2018-07-03 16:31:10,910+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674676, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 144, u'mem_total': 1814656, u'mem_unused': 1506828}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:14,146+0200 DEBUG (jsonrpc/0) [jsonrpc.JsonRpcServer] Calling 'Host.getStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:14,147+0200 INFO  (jsonrpc/0) [api.host] START getStats() from=::ffff:xxx.yyy.215.6,41368 (api:46)
>2018-07-03 16:31:14,147+0200 INFO  (jsonrpc/0) [vdsm.api] START repoStats(domains=()) from=::ffff:xxx.yyy.215.6,41368, task_id=62069031-202d-4552-bad8-e6aa8da45287 (api:46)
>2018-07-03 16:31:14,147+0200 INFO  (jsonrpc/0) [vdsm.api] FINISH repoStats return={u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000173761', 'lastCheck': '0.1', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000279908', 'lastCheck': '0.1', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000167073', 'lastCheck': '0.1', 'valid': True}} from=::ffff:xxx.yyy.215.6,41368, task_id=62069031-202d-4552-bad8-e6aa8da45287 (api:52)
>2018-07-03 16:31:14,148+0200 INFO  (jsonrpc/0) [vdsm.api] START multipath_health() from=::ffff:xxx.yyy.215.6,41368, task_id=1fcd33f3-4d48-46d3-9c98-e84bee5dd84d (api:46)
>2018-07-03 16:31:14,148+0200 INFO  (jsonrpc/0) [vdsm.api] FINISH multipath_health return={} from=::ffff:xxx.yyy.215.6,41368, task_id=1fcd33f3-4d48-46d3-9c98-e84bee5dd84d (api:52)
>2018-07-03 16:31:14,154+0200 INFO  (jsonrpc/0) [api.host] FINISH getStats return={'status': {'message': 'Done', 'code': 0}, 'info': {'cpuStatistics': {'1': {'cpuUser': '0.47', 'nodeIndex': 0, 'cpuSys': '0.40', 'cpuIdle': '99.13'}, '0': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}, '3': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}, '2': {'cpuUser': '0.33', 'nodeIndex': 0, 'cpuSys': '0.13', 'cpuIdle': '99.54'}, '5': {'cpuUser': '0.60', 'nodeIndex': 0, 'cpuSys': '0.13', 'cpuIdle': '99.27'}, '4': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}}, 'numaNodeMemFree': {'0': {'memPercent': 8, 'memFree': '29617'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 1, 'memUsed': '5', 'storageDomains': {u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000173761', 'lastCheck': '0.1', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000279908', 'lastCheck': '0.1', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000167073', 'lastCheck': '0.1', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'bond10.224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.224', 'tx': '1156', 'txDropped': '0', 'rx': '295563790', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.226', 'tx': '1156', 'txDropped': '0', 'rx': '17214226294', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond1', 'tx': '532245919', 'txDropped': '0', 'rx': '118607154', 'rxErrors': '0', 'speed': '2000', 'rxDropped': '19'}, 'enp1s0f1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'enp1s0f1', 'tx': '3823645', 'txDropped': '0', 'rx': '24796578173', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11891'}, 'enp1s0f0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'enp1s0f0', 'tx': '937945273', 'txDropped': '0', 'rx': '35319983528', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11891'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'lo', 'tx': '536452271', 'txDropped': '0', 'rx': '536452271', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'iSCSI': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'iSCSI', 'tx': '904150047', 'txDropped': '0', 'rx': '20484714505', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '605'}, '50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': '50', 'tx': '578', 'txDropped': '0', 'rx': '292100298', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '80180'}, 'bond10.969': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.969', 'tx': '904150625', 'txDropped': '0', 'rx': '30431308341', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vnet0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'vnet0', 'tx': '397777', 'txDropped': '0', 'rx': '28420', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1530628264.599341, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno2': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'eno2', 'tx': '1490192', 'txDropped': '0', 'rx': '76696689', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'eno1', 'tx': '530755727', 'txDropped': '0', 'rx': '41910465', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': '711', 'tx': '578', 'txDropped': '0', 'rx': '185309103', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2387'}, 'bond10': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10', 'tx': '941768918', 'txDropped': '0', 'rx': '60116561701', 'rxErrors': '0', 'speed': '20000', 'rxDropped': '23782'}, 'bond10.711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.711', 'tx': '1156', 'txDropped': '0', 'rx': '2425995056', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': '226', 'tx': '578', 'txDropped': '0', 'rx': '109275745', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.50', 'tx': '15473835', 'txDropped': '0', 'rx': '7290125969', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': '224', 'tx': '578', 'txDropped': '0', 'rx': '132777570', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.468': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.468', 'tx': '620', 'txDropped': '0', 'rx': '47564', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '358'}}, 'txDropped': '0', 'anonHugePages': '756', 'ksmPages': 100, 'elapsedTime': '358513.95', 'cpuLoad': '0.06', 'cpuSys': '0.10', 'diskStats': {'/var/log': {'free': '7924'}, '/var/run/vdsm/': {'free': '15841'}, '/tmp': {'free': '984'}}, 'cpuUserVdsmd': '0.40', 'netConfigDirty': 'False', 'memCommitted': 2113, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 28828L, 'bootTime': '1530268033', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '131113', 'outgoingVmMigrations': 0, 'swapTotal': 26339, 'swapFree': 26339, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-07-03T14:31:14 GMT', 'cpuUser': '0.19', 'memFree': 30429, 'cpuIdle': '99.71', 'vmActive': 1, 'v2vJobs': {}, 'cpuSysVdsmd': '0.20'}} from=::ffff:xxx.yyy.215.6,41368 (api:52)
>2018-07-03 16:31:14,155+0200 DEBUG (jsonrpc/0) [jsonrpc.JsonRpcServer] Return 'Host.getStats' in bridge with {'cpuStatistics': {'1': {'cpuUser': '0.47', 'nodeIndex': 0, 'cpuSys': '0.40', 'cpuIdle': '99.13'}, '0': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}, '3': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}, '2': {'cpuUser': '0.33', 'nodeIndex': 0, 'cpuSys': '0.13', 'cpuIdle': '99.54'}, '5': {'cpuUser': '0.60', 'nodeIndex': 0, 'cpuSys': '0.13', 'cpuIdle': '99.27'}, '4': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}}, 'numaNodeMemFree': {'0': {'memPercent': 8, 'memFree': '29617'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 1, 'memUsed': '5', 'storageDomains': {u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000173761', 'lastCheck': '0.1', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000279908', 'lastCheck': '0.1', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000167073', 'lastCheck': '0.1', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'bond10.224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.224', 'tx': '1156', 'txDropped': '0', 'rx': '295563790', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.226', 'tx': '1156', 'txDropped': '0', 'rx': '17214226294', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond1', 'tx': '532245919', 'txDropped': '0', 'rx': '118607154', 'rxErrors': '0', 'speed': '2000', 'rxDropped': '19'}, 'enp1s0f1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'enp1s0f1', 'tx': '3823645', 'txDropped': '0', 'rx': '24796578173', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11891'}, 'enp1s0f0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'enp1s0f0', 'tx': '937945273', 'txDropped': '0', 'rx': '35319983528', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11891'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'lo', 'tx': '536452271', 'txDropped': '0', 'rx': '536452271', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'iSCSI': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'iSCSI', 'tx': '904150047', 'txDropped': '0', 'rx': '20484714505', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '605'}, '50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': '50', 'tx': '578', 'txDropped': '0', 'rx': '292100298', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '80180'}, 'bond10.969': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.969', 'tx': '904150625', 'txDropped': '0', 'rx': '30431308341', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vnet0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'vnet0', 'tx': '397777', 'txDropped': '0', 'rx': '28420', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1530628264.599341, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno2': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'eno2', 'tx': '1490192', 'txDropped': '0', 'rx': '76696689', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'eno1', 'tx': '530755727', 'txDropped': '0', 'rx': '41910465', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': '711', 'tx': '578', 'txDropped': '0', 'rx': '185309103', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2387'}, 'bond10': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10', 'tx': '941768918', 'txDropped': '0', 'rx': '60116561701', 'rxErrors': '0', 'speed': '20000', 'rxDropped': '23782'}, 'bond10.711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.711', 'tx': '1156', 'txDropped': '0', 'rx': '2425995056', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': '226', 'tx': '578', 'txDropped': '0', 'rx': '109275745', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.50', 'tx': '15473835', 'txDropped': '0', 'rx': '7290125969', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': '224', 'tx': '578', 'txDropped': '0', 'rx': '132777570', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.468': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628264.599341, 'name': 'bond10.468', 'tx': '620', 'txDropped': '0', 'rx': '47564', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '358'}}, 'txDropped': '0', 'anonHugePages': '756', 'ksmPages': 100, 'elapsedTime': '358513.95', 'cpuLoad': '0.06', 'cpuSys': '0.10', 'diskStats': {'/var/log': {'free': '7924'}, '/var/run/vdsm/': {'free': '15841'}, '/tmp': {'free': '984'}}, 'cpuUserVdsmd': '0.40', 'netConfigDirty': 'False', 'memCommitted': 2113, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 28828L, 'bootTime': '1530268033', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '131113', 'outgoingVmMigrations': 0, 'swapTotal': 26339, 'swapFree': 26339, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-07-03T14:31:14 GMT', 'cpuUser': '0.19', 'memFree': 30429, 'cpuIdle': '99.71', 'vmActive': 1, 'v2vJobs': {}, 'cpuSysVdsmd': '0.20'} (__init__:617)
>2018-07-03 16:31:14,156+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call Host.getStats succeeded in 0.01 seconds (__init__:573)
>2018-07-03 16:31:15,917+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674676, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 18, u'mem_total': 1814656, u'mem_unused': 1506828}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:17,036+0200 DEBUG (jsonrpc/1) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:17,036+0200 INFO  (jsonrpc/1) [api.host] START getAllVmStats() from=::ffff:xxx.yyy.215.6,41368 (api:46)
>2018-07-03 16:31:17,037+0200 INFO  (jsonrpc/1) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::ffff:xxx.yyy.215.6,41368 (api:52)
>2018-07-03 16:31:17,037+0200 DEBUG (jsonrpc/1) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmStats' in bridge with (suppressed) (__init__:617)
>2018-07-03 16:31:17,037+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:19,306+0200 DEBUG (qgapoller/2) [vds] Not sending QEMU-GA command 'guest-get-users' to vm_id='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f', command is not supported (qemuguestagent:191)
>2018-07-03 16:31:19,602+0200 DEBUG (jsonrpc/3) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:19,602+0200 INFO  (jsonrpc/3) [api.host] START getAllVmStats() from=::1,48366 (api:46)
>2018-07-03 16:31:19,603+0200 INFO  (jsonrpc/3) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::1,48366 (api:52)
>2018-07-03 16:31:19,603+0200 DEBUG (jsonrpc/3) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmStats' in bridge with (suppressed) (__init__:617)
>2018-07-03 16:31:19,603+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:19,646+0200 DEBUG (jsonrpc/4) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmIoTunePolicies' in bridge with {} (__init__:590)
>2018-07-03 16:31:19,646+0200 INFO  (jsonrpc/4) [api.host] START getAllVmIoTunePolicies() from=::1,48366 (api:46)
>2018-07-03 16:31:19,646+0200 INFO  (jsonrpc/4) [api.host] FINISH getAllVmIoTunePolicies return={'status': {'message': 'Done', 'code': 0}, 'io_tune_policies_dict': {'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f': {'policy': [], 'current_values': [{'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/e79b23b7-03fe-42f2-af61-8dba1d9e9d01/11dd6e3b-6621-4cc3-949d-77eea64f6444', 'name': 'sda'}, {'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/7d8b4f11-9f6a-490c-b847-a4b9f7a70c31/4c27d800-b040-4616-b2d5-e07a2476d51e', 'name': 'sdc'}]}}} from=::1,48366 (api:52)
>2018-07-03 16:31:19,647+0200 DEBUG (jsonrpc/4) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmIoTunePolicies' in bridge with {'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f': {'policy': [], 'current_values': [{'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/e79b23b7-03fe-42f2-af61-8dba1d9e9d01/11dd6e3b-6621-4cc3-949d-77eea64f6444', 'name': 'sda'}, {'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/7d8b4f11-9f6a-490c-b847-a4b9f7a70c31/4c27d800-b040-4616-b2d5-e07a2476d51e', 'name': 'sdc'}]}} (__init__:617)
>2018-07-03 16:31:19,647+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:19,648+0200 INFO  (periodic/1) [vdsm.api] START repoStats(domains=()) from=internal, task_id=9828f92b-1d8f-4ff4-90be-55e76f13db96 (api:46)
>2018-07-03 16:31:19,649+0200 INFO  (periodic/1) [vdsm.api] FINISH repoStats return={u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000173761', 'lastCheck': '3.2', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000279908', 'lastCheck': '4.6', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000167073', 'lastCheck': '3.2', 'valid': True}} from=internal, task_id=9828f92b-1d8f-4ff4-90be-55e76f13db96 (api:52)
>2018-07-03 16:31:19,649+0200 INFO  (periodic/1) [vdsm.api] START multipath_health() from=internal, task_id=0ea05c5c-5674-4ac3-8f94-52a06e74e0e0 (api:46)
>2018-07-03 16:31:19,649+0200 INFO  (periodic/1) [vdsm.api] FINISH multipath_health return={} from=internal, task_id=0ea05c5c-5674-4ac3-8f94-52a06e74e0e0 (api:52)
>2018-07-03 16:31:20,925+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674552, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 143, u'mem_total': 1814656, u'mem_unused': 1506704}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:21,082+0200 DEBUG (periodic/2) [virt.sampling.VMBulkstatsMonitor] sampled timestamp 4654914.62 elapsed 0.010 acquired True domains all (sampling:522)
>2018-07-03 16:31:22,122+0200 DEBUG (jsonrpc/5) [jsonrpc.JsonRpcServer] Calling 'VM.freeze' in bridge with {u'vmID': u'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'} (__init__:590)
>2018-07-03 16:31:22,122+0200 INFO  (jsonrpc/5) [api.virt] START freeze() from=::ffff:xxx.yyy.215.6,41368, flow_id=501bfa6c-c6fb-42c5-b650-0d772d9476f1, vmId=4a8c9902-f9ab-490f-b1dd-82d9aee63b5f (api:46)
>2018-07-03 16:31:22,122+0200 DEBUG (jsonrpc/5) [api] START freeze args=(<vdsm.API.VM object at 0x7f6e18371f50>,) kwargs={} (api:120)
>2018-07-03 16:31:22,122+0200 INFO  (jsonrpc/5) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Freezing guest filesystems (vm:4341)
>2018-07-03 16:31:22,165+0200 INFO  (jsonrpc/5) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') 1 guest filesystems frozen (vm:4356)
>2018-07-03 16:31:22,165+0200 DEBUG (jsonrpc/5) [api] FINISH freeze response={'status': {'message': 'Done', 'code': 0}} (api:135)
>2018-07-03 16:31:22,165+0200 INFO  (jsonrpc/5) [api.virt] FINISH freeze return={'status': {'message': 'Done', 'code': 0}} from=::ffff:xxx.yyy.215.6,41368, flow_id=501bfa6c-c6fb-42c5-b650-0d772d9476f1, vmId=4a8c9902-f9ab-490f-b1dd-82d9aee63b5f (api:52)
>2018-07-03 16:31:22,165+0200 DEBUG (jsonrpc/5) [jsonrpc.JsonRpcServer] Return 'VM.freeze' in bridge with True (__init__:617)
>2018-07-03 16:31:22,165+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call VM.freeze succeeded in 0.04 seconds (__init__:573)
>2018-07-03 16:31:23,518+0200 DEBUG (periodic/3) [virt.periodic] Looking for stale paused VMs (periodic:422)
>2018-07-03 16:31:25,931+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674800, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 185, u'mem_total': 1814656, u'mem_unused': 1506952}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:28,993+0200 DEBUG (jsonrpc/6) [jsonrpc.JsonRpcServer] Calling 'VM.snapshot' in bridge with {u'frozen': True, u'vmID': u'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f', u'snapDrives': []} (__init__:590)
>2018-07-03 16:31:28,993+0200 INFO  (jsonrpc/6) [api.virt] START snapshot(snapDrives=[], snapMemory=None, frozen=True) from=::ffff:xxx.yyy.215.6,41368, flow_id=501bfa6c-c6fb-42c5-b650-0d772d9476f1, vmId=4a8c9902-f9ab-490f-b1dd-82d9aee63b5f (api:46)
>2018-07-03 16:31:28,993+0200 DEBUG (jsonrpc/6) [api] START snapshot args=(<vdsm.API.VM object at 0x7f6e1863a410>, [], None, True) kwargs={} (api:120)
>2018-07-03 16:31:28,994+0200 INFO  (jsonrpc/6) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') <?xml version='1.0' encoding='utf-8'?>
>2018-07-03 16:31:28,994+0200 INFO  (jsonrpc/6) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Disabling drive monitoring (drivemonitor:58)
>2018-07-03 16:31:28,994+0200 INFO  (jsonrpc/6) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Taking a live snapshot (drives=, memory=True) (vm:4561)
>2018-07-03 16:31:29,001+0200 ERROR (jsonrpc/6) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Unable to take snapshot (vm:4565)
>2018-07-03 16:31:29,001+0200 INFO  (jsonrpc/6) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Enabling drive monitoring (drivemonitor:54)
>2018-07-03 16:31:29,001+0200 DEBUG (jsonrpc/6) [api] FINISH snapshot response={'status': {'message': 'Snapshot failed', 'code': 48}} (api:135)
>2018-07-03 16:31:29,001+0200 INFO  (jsonrpc/6) [api.virt] FINISH snapshot return={'status': {'message': 'Snapshot failed', 'code': 48}} from=::ffff:xxx.yyy.215.6,41368, flow_id=501bfa6c-c6fb-42c5-b650-0d772d9476f1, vmId=4a8c9902-f9ab-490f-b1dd-82d9aee63b5f (api:52)
>2018-07-03 16:31:29,001+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call VM.snapshot failed (error 48) in 0.01 seconds (__init__:573)
>2018-07-03 16:31:29,301+0200 DEBUG (qgapoller/0) [vds] Not sending QEMU-GA command 'guest-get-users' to vm_id='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f', command is not supported (qemuguestagent:191)
>2018-07-03 16:31:29,302+0200 DEBUG (jsonrpc/2) [jsonrpc.JsonRpcServer] Calling 'Host.getStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:29,302+0200 INFO  (jsonrpc/2) [api.host] START getStats() from=::ffff:xxx.yyy.215.6,41368 (api:46)
>2018-07-03 16:31:29,302+0200 INFO  (jsonrpc/2) [vdsm.api] START repoStats(domains=()) from=::ffff:xxx.yyy.215.6,41368, task_id=7278b846-7a15-41ff-9f44-6f8ddd25956c (api:46)
>2018-07-03 16:31:29,302+0200 INFO  (jsonrpc/2) [vdsm.api] FINISH repoStats return={u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000158566', 'lastCheck': '2.8', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000288764', 'lastCheck': '4.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000152551', 'lastCheck': '2.8', 'valid': True}} from=::ffff:xxx.yyy.215.6,41368, task_id=7278b846-7a15-41ff-9f44-6f8ddd25956c (api:52)
>2018-07-03 16:31:29,303+0200 INFO  (jsonrpc/2) [vdsm.api] START multipath_health() from=::ffff:xxx.yyy.215.6,41368, task_id=ad17abbe-dddb-4752-8634-0368158623f7 (api:46)
>2018-07-03 16:31:29,303+0200 INFO  (jsonrpc/2) [vdsm.api] FINISH multipath_health return={} from=::ffff:xxx.yyy.215.6,41368, task_id=ad17abbe-dddb-4752-8634-0368158623f7 (api:52)
>2018-07-03 16:31:29,308+0200 INFO  (jsonrpc/2) [api.host] FINISH getStats return={'status': {'message': 'Done', 'code': 0}, 'info': {'cpuStatistics': {'1': {'cpuUser': '0.33', 'nodeIndex': 0, 'cpuSys': '0.27', 'cpuIdle': '99.40'}, '0': {'cpuUser': '0.13', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.87'}, '3': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}, '2': {'cpuUser': '0.20', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.73'}, '5': {'cpuUser': '0.40', 'nodeIndex': 0, 'cpuSys': '0.13', 'cpuIdle': '99.47'}, '4': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}}, 'numaNodeMemFree': {'0': {'memPercent': 8, 'memFree': '29617'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 1, 'memUsed': '5', 'storageDomains': {u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000158566', 'lastCheck': '2.8', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000288764', 'lastCheck': '4.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000152551', 'lastCheck': '2.8', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'bond10.224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.224', 'tx': '1156', 'txDropped': '0', 'rx': '295570523', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.226', 'tx': '1156', 'txDropped': '0', 'rx': '17214229330', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond1', 'tx': '532282248', 'txDropped': '0', 'rx': '118612762', 'rxErrors': '0', 'speed': '2000', 'rxDropped': '19'}, 'enp1s0f1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'enp1s0f1', 'tx': '3824039', 'txDropped': '0', 'rx': '24797705975', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11891'}, 'enp1s0f0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'enp1s0f0', 'tx': '937962715', 'txDropped': '0', 'rx': '35320764903', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11892'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'lo', 'tx': '536475759', 'txDropped': '0', 'rx': '536475759', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'iSCSI': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'iSCSI', 'tx': '904166777', 'txDropped': '0', 'rx': '20485782931', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '605'}, '50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': '50', 'tx': '578', 'txDropped': '0', 'rx': '292112838', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '80184'}, 'bond10.969': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.969', 'tx': '904167355', 'txDropped': '0', 'rx': '30432376767', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vnet0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'vnet0', 'tx': '414569', 'txDropped': '0', 'rx': '29278', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1530628279.626708, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno2': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'eno2', 'tx': '1490316', 'txDropped': '0', 'rx': '76698885', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'eno1', 'tx': '530791932', 'txDropped': '0', 'rx': '41913877', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': '711', 'tx': '578', 'txDropped': '0', 'rx': '185319826', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2387'}, 'bond10': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10', 'tx': '941786754', 'txDropped': '0', 'rx': '60118470878', 'rxErrors': '0', 'speed': '20000', 'rxDropped': '23783'}, 'bond10.711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.711', 'tx': '1156', 'txDropped': '0', 'rx': '2426005779', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': '226', 'tx': '578', 'txDropped': '0', 'rx': '109278781', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.50', 'tx': '15474693', 'txDropped': '0', 'rx': '7290866560', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': '224', 'tx': '578', 'txDropped': '0', 'rx': '132784303', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.468': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.468', 'tx': '620', 'txDropped': '0', 'rx': '47564', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '358'}}, 'txDropped': '0', 'anonHugePages': '756', 'ksmPages': 100, 'elapsedTime': '358529.11', 'cpuLoad': '0.06', 'cpuSys': '0.07', 'diskStats': {'/var/log': {'free': '7924'}, '/var/run/vdsm/': {'free': '15841'}, '/tmp': {'free': '984'}}, 'cpuUserVdsmd': '0.33', 'netConfigDirty': 'False', 'memCommitted': 2113, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 28828L, 'bootTime': '1530268033', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '131119', 'outgoingVmMigrations': 0, 'swapTotal': 26339, 'swapFree': 26339, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-07-03T14:31:29 GMT', 'cpuUser': '0.15', 'memFree': 30429, 'cpuIdle': '99.78', 'vmActive': 1, 'v2vJobs': {}, 'cpuSysVdsmd': '0.20'}} from=::ffff:xxx.yyy.215.6,41368 (api:52)
>2018-07-03 16:31:29,309+0200 DEBUG (jsonrpc/2) [jsonrpc.JsonRpcServer] Return 'Host.getStats' in bridge with {'cpuStatistics': {'1': {'cpuUser': '0.33', 'nodeIndex': 0, 'cpuSys': '0.27', 'cpuIdle': '99.40'}, '0': {'cpuUser': '0.13', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.87'}, '3': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}, '2': {'cpuUser': '0.20', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.73'}, '5': {'cpuUser': '0.40', 'nodeIndex': 0, 'cpuSys': '0.13', 'cpuIdle': '99.47'}, '4': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}}, 'numaNodeMemFree': {'0': {'memPercent': 8, 'memFree': '29617'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 1, 'memUsed': '5', 'storageDomains': {u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000158566', 'lastCheck': '2.8', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000288764', 'lastCheck': '4.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000152551', 'lastCheck': '2.8', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'bond10.224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.224', 'tx': '1156', 'txDropped': '0', 'rx': '295570523', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.226', 'tx': '1156', 'txDropped': '0', 'rx': '17214229330', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond1', 'tx': '532282248', 'txDropped': '0', 'rx': '118612762', 'rxErrors': '0', 'speed': '2000', 'rxDropped': '19'}, 'enp1s0f1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'enp1s0f1', 'tx': '3824039', 'txDropped': '0', 'rx': '24797705975', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11891'}, 'enp1s0f0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'enp1s0f0', 'tx': '937962715', 'txDropped': '0', 'rx': '35320764903', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11892'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'lo', 'tx': '536475759', 'txDropped': '0', 'rx': '536475759', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'iSCSI': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'iSCSI', 'tx': '904166777', 'txDropped': '0', 'rx': '20485782931', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '605'}, '50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': '50', 'tx': '578', 'txDropped': '0', 'rx': '292112838', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '80184'}, 'bond10.969': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.969', 'tx': '904167355', 'txDropped': '0', 'rx': '30432376767', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vnet0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'vnet0', 'tx': '414569', 'txDropped': '0', 'rx': '29278', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1530628279.626708, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno2': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'eno2', 'tx': '1490316', 'txDropped': '0', 'rx': '76698885', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'eno1', 'tx': '530791932', 'txDropped': '0', 'rx': '41913877', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': '711', 'tx': '578', 'txDropped': '0', 'rx': '185319826', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2387'}, 'bond10': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10', 'tx': '941786754', 'txDropped': '0', 'rx': '60118470878', 'rxErrors': '0', 'speed': '20000', 'rxDropped': '23783'}, 'bond10.711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.711', 'tx': '1156', 'txDropped': '0', 'rx': '2426005779', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': '226', 'tx': '578', 'txDropped': '0', 'rx': '109278781', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.50', 'tx': '15474693', 'txDropped': '0', 'rx': '7290866560', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': '224', 'tx': '578', 'txDropped': '0', 'rx': '132784303', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.468': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628279.626708, 'name': 'bond10.468', 'tx': '620', 'txDropped': '0', 'rx': '47564', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '358'}}, 'txDropped': '0', 'anonHugePages': '756', 'ksmPages': 100, 'elapsedTime': '358529.11', 'cpuLoad': '0.06', 'cpuSys': '0.07', 'diskStats': {'/var/log': {'free': '7924'}, '/var/run/vdsm/': {'free': '15841'}, '/tmp': {'free': '984'}}, 'cpuUserVdsmd': '0.33', 'netConfigDirty': 'False', 'memCommitted': 2113, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 28828L, 'bootTime': '1530268033', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '131119', 'outgoingVmMigrations': 0, 'swapTotal': 26339, 'swapFree': 26339, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-07-03T14:31:29 GMT', 'cpuUser': '0.15', 'memFree': 30429, 'cpuIdle': '99.78', 'vmActive': 1, 'v2vJobs': {}, 'cpuSysVdsmd': '0.20'} (__init__:617)
>2018-07-03 16:31:29,309+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call Host.getStats succeeded in 0.01 seconds (__init__:573)
>2018-07-03 16:31:30,176+0200 DEBUG (jsonrpc/7) [jsonrpc.JsonRpcServer] Calling 'VM.thaw' in bridge with {u'vmID': u'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'} (__init__:590)
>2018-07-03 16:31:30,176+0200 INFO  (jsonrpc/7) [api.virt] START thaw() from=::ffff:xxx.yyy.215.6,41368, flow_id=501bfa6c-c6fb-42c5-b650-0d772d9476f1, vmId=4a8c9902-f9ab-490f-b1dd-82d9aee63b5f (api:46)
>2018-07-03 16:31:30,176+0200 DEBUG (jsonrpc/7) [api] START thaw args=(<vdsm.API.VM object at 0x7f6e1863a890>,) kwargs={} (api:120)
>2018-07-03 16:31:30,176+0200 INFO  (jsonrpc/7) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Thawing guest filesystems (vm:4364)
>2018-07-03 16:31:30,180+0200 INFO  (jsonrpc/7) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') 1 guest filesystems thawed (vm:4379)
>2018-07-03 16:31:30,180+0200 DEBUG (jsonrpc/7) [api] FINISH thaw response={'status': {'message': 'Done', 'code': 0}} (api:135)
>2018-07-03 16:31:30,180+0200 INFO  (jsonrpc/7) [api.virt] FINISH thaw return={'status': {'message': 'Done', 'code': 0}} from=::ffff:xxx.yyy.215.6,41368, flow_id=501bfa6c-c6fb-42c5-b650-0d772d9476f1, vmId=4a8c9902-f9ab-490f-b1dd-82d9aee63b5f (api:52)
>2018-07-03 16:31:30,180+0200 DEBUG (jsonrpc/7) [jsonrpc.JsonRpcServer] Return 'VM.thaw' in bridge with True (__init__:617)
>2018-07-03 16:31:30,180+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call VM.thaw succeeded in 0.01 seconds (__init__:573)
>2018-07-03 16:31:30,940+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674780, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 308, u'mem_total': 1814656, u'mem_unused': 1506932}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:32,047+0200 DEBUG (jsonrpc/0) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:32,047+0200 DEBUG (jsonrpc/0) [root] ThreadedHandler is ok in the last 60 seconds (max pending: 5) (logutils:317)
>2018-07-03 16:31:32,047+0200 INFO  (jsonrpc/0) [api.host] START getAllVmStats() from=::ffff:xxx.yyy.215.6,41368 (api:46)
>2018-07-03 16:31:32,048+0200 INFO  (jsonrpc/0) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::ffff:xxx.yyy.215.6,41368 (api:52)
>2018-07-03 16:31:32,049+0200 DEBUG (jsonrpc/0) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmStats' in bridge with (suppressed) (__init__:617)
>2018-07-03 16:31:32,049+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.01 seconds (__init__:573)
>2018-07-03 16:31:34,621+0200 DEBUG (jsonrpc/1) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:34,621+0200 INFO  (jsonrpc/1) [api.host] START getAllVmStats() from=::1,48366 (api:46)
>2018-07-03 16:31:34,622+0200 INFO  (jsonrpc/1) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::1,48366 (api:52)
>2018-07-03 16:31:34,623+0200 DEBUG (jsonrpc/1) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmStats' in bridge with (suppressed) (__init__:617)
>2018-07-03 16:31:34,623+0200 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:34,674+0200 INFO  (periodic/0) [vdsm.api] START repoStats(domains=()) from=internal, task_id=2cd1a2e8-416d-403c-9715-b0997efba831 (api:46)
>2018-07-03 16:31:34,674+0200 INFO  (periodic/0) [vdsm.api] FINISH repoStats return={u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000145257', 'lastCheck': '0.6', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000283392', 'lastCheck': '0.6', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.0001323', 'lastCheck': '0.5', 'valid': True}} from=internal, task_id=2cd1a2e8-416d-403c-9715-b0997efba831 (api:52)
>2018-07-03 16:31:34,675+0200 INFO  (periodic/0) [vdsm.api] START multipath_health() from=internal, task_id=b8138b4c-1cae-447e-b025-fb9dcd8a477d (api:46)
>2018-07-03 16:31:34,675+0200 DEBUG (jsonrpc/3) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmIoTunePolicies' in bridge with {} (__init__:590)
>2018-07-03 16:31:34,675+0200 INFO  (jsonrpc/3) [api.host] START getAllVmIoTunePolicies() from=::1,48366 (api:46)
>2018-07-03 16:31:34,675+0200 INFO  (jsonrpc/3) [api.host] FINISH getAllVmIoTunePolicies return={'status': {'message': 'Done', 'code': 0}, 'io_tune_policies_dict': {'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f': {'policy': [], 'current_values': [{'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/e79b23b7-03fe-42f2-af61-8dba1d9e9d01/11dd6e3b-6621-4cc3-949d-77eea64f6444', 'name': 'sda'}, {'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/7d8b4f11-9f6a-490c-b847-a4b9f7a70c31/4c27d800-b040-4616-b2d5-e07a2476d51e', 'name': 'sdc'}]}}} from=::1,48366 (api:52)
>2018-07-03 16:31:34,675+0200 DEBUG (jsonrpc/3) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmIoTunePolicies' in bridge with {'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f': {'policy': [], 'current_values': [{'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/e79b23b7-03fe-42f2-af61-8dba1d9e9d01/11dd6e3b-6621-4cc3-949d-77eea64f6444', 'name': 'sda'}, {'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/7d8b4f11-9f6a-490c-b847-a4b9f7a70c31/4c27d800-b040-4616-b2d5-e07a2476d51e', 'name': 'sdc'}]}} (__init__:617)
>2018-07-03 16:31:34,676+0200 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:34,676+0200 INFO  (periodic/0) [vdsm.api] FINISH multipath_health return={} from=internal, task_id=b8138b4c-1cae-447e-b025-fb9dcd8a477d (api:52)
>2018-07-03 16:31:35,947+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674780, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 18, u'mem_total': 1814656, u'mem_unused': 1506932}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:36,085+0200 DEBUG (periodic/3) [virt.sampling.VMBulkstatsMonitor] sampled timestamp 4654929.62 elapsed 0.010 acquired True domains all (sampling:522)
>2018-07-03 16:31:36,480+0200 DEBUG (itmap/0) [root] START thread <Thread(itmap/0, started daemon 140108367898368)> (func=<function wrapper at 0x7f6e185b5410>, args=('/rhev/data-center/mnt/tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-iso',), kwargs={}) (concurrent:192)
>2018-07-03 16:31:36,481+0200 INFO  (itmap/0) [IOProcessClient] Starting client /tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-iso (__init__:308)
>2018-07-03 16:31:36,481+0200 DEBUG (itmap/0) [IOProcessClient] Starting ioprocess for client /tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-iso (__init__:320)
>2018-07-03 16:31:36,483+0200 DEBUG (itmap/0) [root] START thread <Thread(itmap/0, started daemon 140108401469184)> (func=<function wrapper at 0x7f6e18232f50>, args=('/rhev/data-center/mnt/tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-iso',), kwargs={}) (concurrent:192)
>2018-07-03 16:31:36,484+0200 DEBUG (itmap/1) [root] START thread <Thread(itmap/1, started daemon 140108762158848)> (func=<function wrapper at 0x7f6e185b5410>, args=('/rhev/data-center/mnt/tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-export',), kwargs={}) (concurrent:192)
>2018-07-03 16:31:36,488+0200 DEBUG (itmap/0) [IOProcessClient] Starting communication thread for client /tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-iso (__init__:376)
>2018-07-03 16:31:36,489+0200 DEBUG (itmap/1) [root] START thread <Thread(itmap/1, started daemon 140110490236672)> (func=<function wrapper at 0x7f6e18232f50>, args=('/rhev/data-center/mnt/tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-export',), kwargs={}) (concurrent:192)
>2018-07-03 16:31:36,489+0200 DEBUG (itmap/0) [IOProcessClient] Communication thread for client /tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-iso started (__init__:388)
>2018-07-03 16:31:36,489+0200 INFO  (itmap/1) [IOProcessClient] Starting client /tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-export (__init__:308)
>2018-07-03 16:31:36,490+0200 DEBUG (itmap/1) [IOProcessClient] Starting ioprocess for client /tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-export (__init__:320)
>2018-07-03 16:31:36,491+0200 INFO  (ioprocess/21792) [IOProcess] Starting ioprocess (__init__:437)
>2018-07-03 16:31:36,496+0200 DEBUG (itmap/1) [IOProcessClient] Starting communication thread for client /tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-export (__init__:376)
>2018-07-03 16:31:36,497+0200 DEBUG (itmap/0) [root] FINISH thread <Thread(itmap/0, started daemon 140108401469184)> (concurrent:195)
>2018-07-03 16:31:36,498+0200 DEBUG (itmap/0) [root] FINISH thread <Thread(itmap/0, started daemon 140108367898368)> (concurrent:195)
>2018-07-03 16:31:36,498+0200 DEBUG (itmap/1) [IOProcessClient] Communication thread for client /tentakel8.ceph.foo.bar:_mnt_default_ovirt-nfs-export started (__init__:388)
>2018-07-03 16:31:36,499+0200 INFO  (ioprocess/21799) [IOProcess] Starting ioprocess (__init__:437)
>2018-07-03 16:31:36,500+0200 DEBUG (itmap/1) [root] FINISH thread <Thread(itmap/1, started daemon 140108762158848)> (concurrent:195)
>2018-07-03 16:31:36,501+0200 INFO  (monitor/2f53e25) [storage.StorageDomain] Removing remnants of deleted images [] (fileSD:733)
>2018-07-03 16:31:36,502+0200 DEBUG (itmap/1) [root] FINISH thread <Thread(itmap/1, started daemon 140110490236672)> (concurrent:195)
>2018-07-03 16:31:36,504+0200 INFO  (monitor/363c0cb) [storage.StorageDomain] Removing remnants of deleted images [] (fileSD:733)
>2018-07-03 16:31:39,306+0200 DEBUG (qgapoller/2) [vds] Not sending QEMU-GA command 'guest-get-users' to vm_id='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f', command is not supported (qemuguestagent:191)
>2018-07-03 16:31:40,952+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674780, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 144, u'mem_total': 1814656, u'mem_unused': 1506932}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:44,324+0200 DEBUG (jsonrpc/4) [jsonrpc.JsonRpcServer] Calling 'Host.getStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:44,324+0200 INFO  (jsonrpc/4) [api.host] START getStats() from=::ffff:xxx.yyy.215.6,41368 (api:46)
>2018-07-03 16:31:44,325+0200 INFO  (jsonrpc/4) [vdsm.api] START repoStats(domains=()) from=::ffff:xxx.yyy.215.6,41368, task_id=5d149e5b-7040-4d54-bb88-3324ee5f61ca (api:46)
>2018-07-03 16:31:44,325+0200 INFO  (jsonrpc/4) [vdsm.api] FINISH repoStats return={u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000168535', 'lastCheck': '0.2', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000287213', 'lastCheck': '0.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000140146', 'lastCheck': '0.2', 'valid': True}} from=::ffff:xxx.yyy.215.6,41368, task_id=5d149e5b-7040-4d54-bb88-3324ee5f61ca (api:52)
>2018-07-03 16:31:44,325+0200 INFO  (jsonrpc/4) [vdsm.api] START multipath_health() from=::ffff:xxx.yyy.215.6,41368, task_id=c6e89424-6b31-4548-9017-71af8b47edbb (api:46)
>2018-07-03 16:31:44,325+0200 INFO  (jsonrpc/4) [vdsm.api] FINISH multipath_health return={} from=::ffff:xxx.yyy.215.6,41368, task_id=c6e89424-6b31-4548-9017-71af8b47edbb (api:52)
>2018-07-03 16:31:44,331+0200 INFO  (jsonrpc/4) [api.host] FINISH getStats return={'status': {'message': 'Done', 'code': 0}, 'info': {'cpuStatistics': {'1': {'cpuUser': '0.53', 'nodeIndex': 0, 'cpuSys': '0.47', 'cpuIdle': '99.00'}, '0': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.86'}, '3': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.86'}, '2': {'cpuUser': '0.33', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.60'}, '5': {'cpuUser': '0.33', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.60'}, '4': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}}, 'numaNodeMemFree': {'0': {'memPercent': 8, 'memFree': '29617'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 1, 'memUsed': '5', 'storageDomains': {u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000168535', 'lastCheck': '0.2', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000287213', 'lastCheck': '0.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000140146', 'lastCheck': '0.2', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'bond10.224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.224', 'tx': '1156', 'txDropped': '0', 'rx': '295577297', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.226', 'tx': '1156', 'txDropped': '0', 'rx': '17214235424', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond1', 'tx': '532326099', 'txDropped': '0', 'rx': '118619693', 'rxErrors': '0', 'speed': '2000', 'rxDropped': '19'}, 'enp1s0f1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'enp1s0f1', 'tx': '3824039', 'txDropped': '0', 'rx': '24797806725', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11892'}, 'enp1s0f0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'enp1s0f0', 'tx': '938103921', 'txDropped': '0', 'rx': '35320795156', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11892'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'lo', 'tx': '536499170', 'txDropped': '0', 'rx': '536499170', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'iSCSI': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'iSCSI', 'tx': '904302907', 'txDropped': '0', 'rx': '20485866837', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '605'}, '50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': '50', 'tx': '578', 'txDropped': '0', 'rx': '292122490', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '80188'}, 'bond10.969': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.969', 'tx': '904303485', 'txDropped': '0', 'rx': '30432460673', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vnet0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'vnet0', 'tx': '427461', 'txDropped': '0', 'rx': '29866', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1530628294.65443, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno2': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'eno2', 'tx': '1490316', 'txDropped': '0', 'rx': '76703866', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'eno1', 'tx': '530835783', 'txDropped': '0', 'rx': '41915827', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': '711', 'tx': '578', 'txDropped': '0', 'rx': '185331385', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2387'}, 'bond10': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10', 'tx': '941927960', 'txDropped': '0', 'rx': '60118601881', 'rxErrors': '0', 'speed': '20000', 'rxDropped': '23784'}, 'bond10.711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.711', 'tx': '1156', 'txDropped': '0', 'rx': '2426017384', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': '226', 'tx': '578', 'txDropped': '0', 'rx': '109284875', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.50', 'tx': '15475281', 'txDropped': '0', 'rx': '7290876820', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': '224', 'tx': '578', 'txDropped': '0', 'rx': '132791077', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.468': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.468', 'tx': '620', 'txDropped': '0', 'rx': '47564', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '358'}}, 'txDropped': '0', 'anonHugePages': '756', 'ksmPages': 100, 'elapsedTime': '358544.13', 'cpuLoad': '0.05', 'cpuSys': '0.10', 'diskStats': {'/var/log': {'free': '7924'}, '/var/run/vdsm/': {'free': '15841'}, '/tmp': {'free': '984'}}, 'cpuUserVdsmd': '0.33', 'netConfigDirty': 'False', 'memCommitted': 2113, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 28825L, 'bootTime': '1530268033', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '131125', 'outgoingVmMigrations': 0, 'swapTotal': 26339, 'swapFree': 26339, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-07-03T14:31:44 GMT', 'cpuUser': '0.16', 'memFree': 30426, 'cpuIdle': '99.74', 'vmActive': 1, 'v2vJobs': {}, 'cpuSysVdsmd': '0.20'}} from=::ffff:xxx.yyy.215.6,41368 (api:52)
>2018-07-03 16:31:44,333+0200 DEBUG (jsonrpc/4) [jsonrpc.JsonRpcServer] Return 'Host.getStats' in bridge with {'cpuStatistics': {'1': {'cpuUser': '0.53', 'nodeIndex': 0, 'cpuSys': '0.47', 'cpuIdle': '99.00'}, '0': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.86'}, '3': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.86'}, '2': {'cpuUser': '0.33', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.60'}, '5': {'cpuUser': '0.33', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.60'}, '4': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}}, 'numaNodeMemFree': {'0': {'memPercent': 8, 'memFree': '29617'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 1, 'memUsed': '5', 'storageDomains': {u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000168535', 'lastCheck': '0.2', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000287213', 'lastCheck': '0.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000140146', 'lastCheck': '0.2', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'bond10.224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.224', 'tx': '1156', 'txDropped': '0', 'rx': '295577297', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.226', 'tx': '1156', 'txDropped': '0', 'rx': '17214235424', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond1', 'tx': '532326099', 'txDropped': '0', 'rx': '118619693', 'rxErrors': '0', 'speed': '2000', 'rxDropped': '19'}, 'enp1s0f1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'enp1s0f1', 'tx': '3824039', 'txDropped': '0', 'rx': '24797806725', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11892'}, 'enp1s0f0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'enp1s0f0', 'tx': '938103921', 'txDropped': '0', 'rx': '35320795156', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11892'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'lo', 'tx': '536499170', 'txDropped': '0', 'rx': '536499170', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'iSCSI': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'iSCSI', 'tx': '904302907', 'txDropped': '0', 'rx': '20485866837', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '605'}, '50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': '50', 'tx': '578', 'txDropped': '0', 'rx': '292122490', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '80188'}, 'bond10.969': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.969', 'tx': '904303485', 'txDropped': '0', 'rx': '30432460673', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vnet0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'vnet0', 'tx': '427461', 'txDropped': '0', 'rx': '29866', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1530628294.65443, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno2': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'eno2', 'tx': '1490316', 'txDropped': '0', 'rx': '76703866', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'eno1', 'tx': '530835783', 'txDropped': '0', 'rx': '41915827', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': '711', 'tx': '578', 'txDropped': '0', 'rx': '185331385', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2387'}, 'bond10': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10', 'tx': '941927960', 'txDropped': '0', 'rx': '60118601881', 'rxErrors': '0', 'speed': '20000', 'rxDropped': '23784'}, 'bond10.711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.711', 'tx': '1156', 'txDropped': '0', 'rx': '2426017384', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': '226', 'tx': '578', 'txDropped': '0', 'rx': '109284875', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.50', 'tx': '15475281', 'txDropped': '0', 'rx': '7290876820', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': '224', 'tx': '578', 'txDropped': '0', 'rx': '132791077', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.468': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628294.65443, 'name': 'bond10.468', 'tx': '620', 'txDropped': '0', 'rx': '47564', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '358'}}, 'txDropped': '0', 'anonHugePages': '756', 'ksmPages': 100, 'elapsedTime': '358544.13', 'cpuLoad': '0.05', 'cpuSys': '0.10', 'diskStats': {'/var/log': {'free': '7924'}, '/var/run/vdsm/': {'free': '15841'}, '/tmp': {'free': '984'}}, 'cpuUserVdsmd': '0.33', 'netConfigDirty': 'False', 'memCommitted': 2113, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 28825L, 'bootTime': '1530268033', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '131125', 'outgoingVmMigrations': 0, 'swapTotal': 26339, 'swapFree': 26339, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-07-03T14:31:44 GMT', 'cpuUser': '0.16', 'memFree': 30426, 'cpuIdle': '99.74', 'vmActive': 1, 'v2vJobs': {}, 'cpuSysVdsmd': '0.20'} (__init__:617)
>2018-07-03 16:31:44,334+0200 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call Host.getStats succeeded in 0.01 seconds (__init__:573)
>2018-07-03 16:31:45,959+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674780, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 18, u'mem_total': 1814656, u'mem_unused': 1506932}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:47,073+0200 DEBUG (jsonrpc/5) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:47,074+0200 INFO  (jsonrpc/5) [api.host] START getAllVmStats() from=::ffff:xxx.yyy.215.6,41368 (api:46)
>2018-07-03 16:31:47,075+0200 INFO  (jsonrpc/5) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::ffff:xxx.yyy.215.6,41368 (api:52)
>2018-07-03 16:31:47,075+0200 DEBUG (jsonrpc/5) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmStats' in bridge with (suppressed) (__init__:617)
>2018-07-03 16:31:47,075+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:49,300+0200 DEBUG (qgapoller/0) [vds] Not sending QEMU-GA command 'guest-get-users' to vm_id='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f', command is not supported (qemuguestagent:191)
>2018-07-03 16:31:49,635+0200 DEBUG (jsonrpc/6) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:49,635+0200 INFO  (jsonrpc/6) [api.host] START getAllVmStats() from=::1,48366 (api:46)
>2018-07-03 16:31:49,636+0200 INFO  (jsonrpc/6) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::1,48366 (api:52)
>2018-07-03 16:31:49,636+0200 DEBUG (jsonrpc/6) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmStats' in bridge with (suppressed) (__init__:617)
>2018-07-03 16:31:49,636+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:49,701+0200 DEBUG (jsonrpc/2) [jsonrpc.JsonRpcServer] Calling 'Host.getAllVmIoTunePolicies' in bridge with {} (__init__:590)
>2018-07-03 16:31:49,701+0200 INFO  (jsonrpc/2) [api.host] START getAllVmIoTunePolicies() from=::1,48366 (api:46)
>2018-07-03 16:31:49,701+0200 INFO  (jsonrpc/2) [api.host] FINISH getAllVmIoTunePolicies return={'status': {'message': 'Done', 'code': 0}, 'io_tune_policies_dict': {'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f': {'policy': [], 'current_values': [{'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/e79b23b7-03fe-42f2-af61-8dba1d9e9d01/11dd6e3b-6621-4cc3-949d-77eea64f6444', 'name': 'sda'}, {'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/7d8b4f11-9f6a-490c-b847-a4b9f7a70c31/4c27d800-b040-4616-b2d5-e07a2476d51e', 'name': 'sdc'}]}}} from=::1,48366 (api:52)
>2018-07-03 16:31:49,702+0200 DEBUG (jsonrpc/2) [jsonrpc.JsonRpcServer] Return 'Host.getAllVmIoTunePolicies' in bridge with {'4a8c9902-f9ab-490f-b1dd-82d9aee63b5f': {'policy': [], 'current_values': [{'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/e79b23b7-03fe-42f2-af61-8dba1d9e9d01/11dd6e3b-6621-4cc3-949d-77eea64f6444', 'name': 'sda'}, {'ioTune': {'write_bytes_sec': 0L, 'total_iops_sec': 0L, 'read_iops_sec': 0L, 'read_bytes_sec': 0L, 'write_iops_sec': 0L, 'total_bytes_sec': 0L}, 'path': '/rhev/data-center/mnt/blockSD/ce86cad9-67d2-44e2-b4ab-f445f856e274/images/7d8b4f11-9f6a-490c-b847-a4b9f7a70c31/4c27d800-b040-4616-b2d5-e07a2476d51e', 'name': 'sdc'}]}} (__init__:617)
>2018-07-03 16:31:49,702+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmIoTunePolicies succeeded in 0.00 seconds (__init__:573)
>2018-07-03 16:31:49,703+0200 INFO  (periodic/1) [vdsm.api] START repoStats(domains=()) from=internal, task_id=bf37ab30-9178-486c-a320-2b3fb6b93a10 (api:46)
>2018-07-03 16:31:49,703+0200 INFO  (periodic/1) [vdsm.api] FINISH repoStats return={u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000168535', 'lastCheck': '3.2', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000287213', 'lastCheck': '4.7', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000140146', 'lastCheck': '3.2', 'valid': True}} from=internal, task_id=bf37ab30-9178-486c-a320-2b3fb6b93a10 (api:52)
>2018-07-03 16:31:49,704+0200 INFO  (periodic/1) [vdsm.api] START multipath_health() from=internal, task_id=5e3f35f4-4a8c-447f-993f-5d9f4b775f2e (api:46)
>2018-07-03 16:31:49,704+0200 INFO  (periodic/1) [vdsm.api] FINISH multipath_health return={} from=internal, task_id=5e3f35f4-4a8c-447f-993f-5d9f4b775f2e (api:52)
>2018-07-03 16:31:50,967+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674780, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 143, u'mem_total': 1814656, u'mem_unused': 1506932}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:51,077+0200 DEBUG (periodic/2) [virt.sampling.VMBulkstatsMonitor] sampled timestamp 4654944.62 elapsed 0.000 acquired True domains all (sampling:522)
>2018-07-03 16:31:55,974+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message heartbeat: {u'memory-stat': {u'swap_out': 0, u'majflt': 0, u'swap_usage': 0, u'mem_cached': 165772, u'mem_free': 1674780, u'mem_buffers': 2076, u'swap_in': 0, u'swap_total': 0, u'pageflt': 18, u'mem_total': 1814656, u'mem_unused': 1506932}, u'free-ram': u'1635', u'apiVersion': 3} (guestagent:337)
>2018-07-03 16:31:56,155+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message applications: {u'applications': [u'kernel-3.10.0-693.2.2.el7', u'kernel-3.10.0-693.21.1.el7', u'ovirt-guest-agent-common-1.0.14-1.el7', u'kernel-3.10.0-862.3.3.el7', u'kernel-3.10.0-693.17.1.el7', u'kernel-3.10.0-693.5.2.el7']} (guestagent:337)
>2018-07-03 16:31:56,174+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message containers: {u'list': []} (guestagent:337)
>2018-07-03 16:31:56,175+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message host-name: {u'name': u'ovirt-test01.srv.foo.bar'} (guestagent:337)
>2018-07-03 16:31:56,175+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message os-version: {u'version': u'3.10.0-862.3.3.el7.x86_64'} (guestagent:337)
>2018-07-03 16:31:56,176+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message network-interfaces: {u'interfaces': [{u'hw': u'00:1a:4a:15:01:51', u'name': u'eth0', u'inet': [u'xxx.yyy.51.76'], u'inet6': [u'fe80::21a:4aff:fe15:151']}]} (guestagent:337)
>2018-07-03 16:31:56,177+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message fqdn: {u'fqdn': u'ovirt-test01.srv.foo.bar'} (guestagent:337)
>2018-07-03 16:31:56,177+0200 DEBUG (vmchannels) [virt.vm] (vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f') Guest's message number-of-cpus: {u'count': 1} (guestagent:337)
>2018-07-03 16:31:59,306+0200 DEBUG (qgapoller/2) [vds] Not sending QEMU-GA command 'guest-get-users' to vm_id='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f', command is not supported (qemuguestagent:191)
>2018-07-03 16:31:59,355+0200 DEBUG (jsonrpc/7) [jsonrpc.JsonRpcServer] Calling 'Host.getStats' in bridge with {} (__init__:590)
>2018-07-03 16:31:59,356+0200 INFO  (jsonrpc/7) [api.host] START getStats() from=::ffff:xxx.yyy.215.6,41368 (api:46)
>2018-07-03 16:31:59,356+0200 INFO  (jsonrpc/7) [vdsm.api] START repoStats(domains=()) from=::ffff:xxx.yyy.215.6,41368, task_id=c01f0899-1dfd-4add-9071-a89749c394d4 (api:46)
>2018-07-03 16:31:59,356+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH repoStats return={u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000163237', 'lastCheck': '2.9', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000271695', 'lastCheck': '4.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000186092', 'lastCheck': '2.8', 'valid': True}} from=::ffff:xxx.yyy.215.6,41368, task_id=c01f0899-1dfd-4add-9071-a89749c394d4 (api:52)
>2018-07-03 16:31:59,356+0200 INFO  (jsonrpc/7) [vdsm.api] START multipath_health() from=::ffff:xxx.yyy.215.6,41368, task_id=7792b887-a055-404c-9143-82a900207739 (api:46)
>2018-07-03 16:31:59,356+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH multipath_health return={} from=::ffff:xxx.yyy.215.6,41368, task_id=7792b887-a055-404c-9143-82a900207739 (api:52)
>2018-07-03 16:31:59,361+0200 INFO  (jsonrpc/7) [api.host] FINISH getStats return={'status': {'message': 'Done', 'code': 0}, 'info': {'cpuStatistics': {'1': {'cpuUser': '0.47', 'nodeIndex': 0, 'cpuSys': '0.40', 'cpuIdle': '99.13'}, '0': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.86'}, '3': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}, '2': {'cpuUser': '0.20', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.73'}, '5': {'cpuUser': '0.47', 'nodeIndex': 0, 'cpuSys': '0.13', 'cpuIdle': '99.40'}, '4': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}}, 'numaNodeMemFree': {'0': {'memPercent': 8, 'memFree': '29614'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 1, 'memUsed': '5', 'storageDomains': {u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000163237', 'lastCheck': '2.9', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000271695', 'lastCheck': '4.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000186092', 'lastCheck': '2.8', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'bond10.224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.224', 'tx': '1156', 'txDropped': '0', 'rx': '295592261', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.226', 'tx': '1156', 'txDropped': '0', 'rx': '17214239834', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond1', 'tx': '532367846', 'txDropped': '0', 'rx': '118626533', 'rxErrors': '0', 'speed': '2000', 'rxDropped': '19'}, 'enp1s0f1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'enp1s0f1', 'tx': '3824163', 'txDropped': '0', 'rx': '24798950649', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11892'}, 'enp1s0f0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'enp1s0f0', 'tx': '938129085', 'txDropped': '0', 'rx': '35320828312', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11893'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'lo', 'tx': '536522665', 'txDropped': '0', 'rx': '536522665', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'iSCSI': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'iSCSI', 'tx': '904327359', 'txDropped': '0', 'rx': '20486945547', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '605'}, '50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': '50', 'tx': '578', 'txDropped': '0', 'rx': '292134788', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '80191'}, 'bond10.969': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.969', 'tx': '904327937', 'txDropped': '0', 'rx': '30433539383', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vnet0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'vnet0', 'tx': '443209', 'txDropped': '0', 'rx': '30454', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1530628309.681665, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno2': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'eno2', 'tx': '1490440', 'txDropped': '0', 'rx': '76706062', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'eno1', 'tx': '530877406', 'txDropped': '0', 'rx': '41920471', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': '711', 'tx': '578', 'txDropped': '0', 'rx': '185341979', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2387'}, 'bond10': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10', 'tx': '941953248', 'txDropped': '0', 'rx': '60119778961', 'rxErrors': '0', 'speed': '20000', 'rxDropped': '23785'}, 'bond10.711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.711', 'tx': '1156', 'txDropped': '0', 'rx': '2426027978', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': '226', 'tx': '578', 'txDropped': '0', 'rx': '109289285', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.50', 'tx': '15475869', 'txDropped': '0', 'rx': '7290889726', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': '224', 'tx': '578', 'txDropped': '0', 'rx': '132798499', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.468': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.468', 'tx': '620', 'txDropped': '0', 'rx': '47564', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '358'}}, 'txDropped': '0', 'anonHugePages': '758', 'ksmPages': 100, 'elapsedTime': '358559.16', 'cpuLoad': '0.05', 'cpuSys': '0.09', 'diskStats': {'/var/log': {'free': '7924'}, '/var/run/vdsm/': {'free': '15841'}, '/tmp': {'free': '984'}}, 'cpuUserVdsmd': '0.33', 'netConfigDirty': 'False', 'memCommitted': 2113, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 28825L, 'bootTime': '1530268033', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '131130', 'outgoingVmMigrations': 0, 'swapTotal': 26339, 'swapFree': 26339, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-07-03T14:31:59 GMT', 'cpuUser': '0.17', 'memFree': 30426, 'cpuIdle': '99.74', 'vmActive': 1, 'v2vJobs': {}, 'cpuSysVdsmd': '0.27'}} from=::ffff:xxx.yyy.215.6,41368 (api:52)
>2018-07-03 16:31:59,361+0200 DEBUG (jsonrpc/7) [jsonrpc.JsonRpcServer] Return 'Host.getStats' in bridge with {'cpuStatistics': {'1': {'cpuUser': '0.47', 'nodeIndex': 0, 'cpuSys': '0.40', 'cpuIdle': '99.13'}, '0': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.86'}, '3': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}, '2': {'cpuUser': '0.20', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.73'}, '5': {'cpuUser': '0.47', 'nodeIndex': 0, 'cpuSys': '0.13', 'cpuIdle': '99.40'}, '4': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}}, 'numaNodeMemFree': {'0': {'memPercent': 8, 'memFree': '29614'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 1, 'memUsed': '5', 'storageDomains': {u'2f53e25a-80bb-486f-bf72-976071408884': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000163237', 'lastCheck': '2.9', 'valid': True}, u'ce86cad9-67d2-44e2-b4ab-f445f856e274': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000271695', 'lastCheck': '4.3', 'valid': True}, u'363c0cb2-b33c-4ea9-8770-b133f2d8f176': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000186092', 'lastCheck': '2.8', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'bond10.224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.224', 'tx': '1156', 'txDropped': '0', 'rx': '295592261', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.226', 'tx': '1156', 'txDropped': '0', 'rx': '17214239834', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond1', 'tx': '532367846', 'txDropped': '0', 'rx': '118626533', 'rxErrors': '0', 'speed': '2000', 'rxDropped': '19'}, 'enp1s0f1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'enp1s0f1', 'tx': '3824163', 'txDropped': '0', 'rx': '24798950649', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11892'}, 'enp1s0f0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'enp1s0f0', 'tx': '938129085', 'txDropped': '0', 'rx': '35320828312', 'rxErrors': '0', 'speed': '10000', 'rxDropped': '11893'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'lo', 'tx': '536522665', 'txDropped': '0', 'rx': '536522665', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'iSCSI': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'iSCSI', 'tx': '904327359', 'txDropped': '0', 'rx': '20486945547', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '605'}, '50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': '50', 'tx': '578', 'txDropped': '0', 'rx': '292134788', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '80191'}, 'bond10.969': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.969', 'tx': '904327937', 'txDropped': '0', 'rx': '30433539383', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vnet0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'vnet0', 'tx': '443209', 'txDropped': '0', 'rx': '30454', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1530628309.681665, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno2': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'eno2', 'tx': '1490440', 'txDropped': '0', 'rx': '76706062', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'eno1': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'eno1', 'tx': '530877406', 'txDropped': '0', 'rx': '41920471', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': '711', 'tx': '578', 'txDropped': '0', 'rx': '185341979', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2387'}, 'bond10': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10', 'tx': '941953248', 'txDropped': '0', 'rx': '60119778961', 'rxErrors': '0', 'speed': '20000', 'rxDropped': '23785'}, 'bond10.711': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.711', 'tx': '1156', 'txDropped': '0', 'rx': '2426027978', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '226': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': '226', 'tx': '578', 'txDropped': '0', 'rx': '109289285', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.50': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.50', 'tx': '15475869', 'txDropped': '0', 'rx': '7290889726', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, '224': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': '224', 'tx': '578', 'txDropped': '0', 'rx': '132798499', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'bond10.468': {'txErrors': '0', 'state': 'up', 'sampleTime': 1530628309.681665, 'name': 'bond10.468', 'tx': '620', 'txDropped': '0', 'rx': '47564', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '358'}}, 'txDropped': '0', 'anonHugePages': '758', 'ksmPages': 100, 'elapsedTime': '358559.16', 'cpuLoad': '0.05', 'cpuSys': '0.09', 'diskStats': {'/var/log': {'free': '7924'}, '/var/run/vdsm/': {'free': '15841'}, '/tmp': {'free': '984'}}, 'cpuUserVdsmd': '0.33', 'netConfigDirty': 'False', 'memCommitted': 2113, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 28825L, 'bootTime': '1530268033', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '131130', 'outgoingVmMigrations': 0, 'swapTotal': 26339, 'swapFree': 26339, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-07-03T14:31:59 GMT', 'cpuUser': '0.17', 'memFree': 30426, 'cpuIdle': '99.74', 'vmActive': 1, 'v2vJobs': {}, 'cpuSysVdsmd': '0.27'} (__init__:617)
>2018-07-03 16:31:59,362+0200 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call Host.getStats succeeded in 0.01 seconds (__init__:573)

Actions: View

Attachments on bug 1596619: 1455487 | 1456264 | 1456266 | 1456267 | 1456268 | 1456461 | 1456462 | 1456600 | 1456601 | 1456602 | 1456603