Login
[x]
Log in using an account from:
Fedora Account System
Red Hat Associate
Red Hat Customer
Or login using a Red Hat Bugzilla account
Forgot Password
Login:
Hide Forgot
Create an Account
Red Hat Bugzilla – Attachment 902418 Details for
Bug 1104697
SPICE connection to VM no longer seamless with 12th login
[?]
New
Simple Search
Advanced Search
My Links
Browse
Requests
Reports
Current State
Search
Tabular reports
Graphical reports
Duplicates
Other Reports
User Changes
Plotly Reports
Bug Status
Bug Severity
Non-Defaults
|
Product Dashboard
Help
Page Help!
Bug Writing Guidelines
What's new
Browser Support Policy
5.0.4.rh83 Release notes
FAQ
Guides index
User guide
Web Services
Contact
Legal
This site requires JavaScript to be enabled to function correctly, please enable it.
vdsm
vdsm.log.mst (text/plain), 76.50 KB, created by
Markus Stockhausen
on 2014-06-05 07:28:24 UTC
(
hide
)
Description:
vdsm
Filename:
MIME Type:
Creator:
Markus Stockhausen
Created:
2014-06-05 07:28:24 UTC
Size:
76.50 KB
patch
obsolete
>Thread-20::DEBUG::2014-06-05 09:24:58,050::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-20::DEBUG::2014-06-05 09:24:58,058::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000261295 s, 2.1 MB/s\n'; <rc> = 0 >Thread-19::DEBUG::2014-06-05 09:25:00,790::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-19::DEBUG::2014-06-05 09:25:00,798::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n644 bytes (644 B) copied, 0.000217707 s, 3.0 MB/s\n'; <rc> = 0 >Thread-27::DEBUG::2014-06-05 09:25:00,950::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-27::DEBUG::2014-06-05 09:25:00,961::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n363 bytes (363 B) copied, 0.000227196 s, 1.6 MB/s\n'; <rc> = 0 >Thread-32::DEBUG::2014-06-05 09:25:00,978::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-32::DEBUG::2014-06-05 09:25:00,985::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000245901 s, 2.3 MB/s\n'; <rc> = 0 >Thread-21::DEBUG::2014-06-05 09:25:02,495::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-21::DEBUG::2014-06-05 09:25:02,503::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n357 bytes (357 B) copied, 0.000267849 s, 1.3 MB/s\n'; <rc> = 0 >Thread-20::DEBUG::2014-06-05 09:25:08,068::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-20::DEBUG::2014-06-05 09:25:08,075::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000309093 s, 1.8 MB/s\n'; <rc> = 0 >Thread-63529::DEBUG::2014-06-05 09:25:09,296::task::595::TaskManager.Task::(_updateState) Task=`c3673cde-b97c-4e4f-8179-0f7d730c31a5`::moving from state init -> state preparing >Thread-63529::INFO::2014-06-05 09:25:09,297::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) >Thread-63529::INFO::2014-06-05 09:25:09,297::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-8215-e15f55f66906': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000217707', 'lastCheck': '8.5', 'valid': True}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000309093', 'lastCheck': '1.2', 'valid': True}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000267849', 'lastCheck': '6.8', 'valid': True}, '63041fa9-e093-4b44-b36f-f39f16d3974f': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000227196', 'lastCheck': '8.3', 'valid': True}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000245901', 'lastCheck': '8.3', 'valid': True}} >Thread-63529::DEBUG::2014-06-05 09:25:09,297::task::1185::TaskManager.Task::(prepare) Task=`c3673cde-b97c-4e4f-8179-0f7d730c31a5`::finished: {'2c51d320-88ce-4f23-8215-e15f55f66906': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000217707', 'lastCheck': '8.5', 'valid': True}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000309093', 'lastCheck': '1.2', 'valid': True}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000267849', 'lastCheck': '6.8', 'valid': True}, '63041fa9-e093-4b44-b36f-f39f16d3974f': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000227196', 'lastCheck': '8.3', 'valid': True}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000245901', 'lastCheck': '8.3', 'valid': True}} >Thread-63529::DEBUG::2014-06-05 09:25:09,298::task::595::TaskManager.Task::(_updateState) Task=`c3673cde-b97c-4e4f-8179-0f7d730c31a5`::moving from state preparing -> state finished >Thread-63529::DEBUG::2014-06-05 09:25:09,298::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-63529::DEBUG::2014-06-05 09:25:09,298::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-63529::DEBUG::2014-06-05 09:25:09,298::task::990::TaskManager.Task::(_decref) Task=`c3673cde-b97c-4e4f-8179-0f7d730c31a5`::ref 0 aborting False >Thread-19::DEBUG::2014-06-05 09:25:10,811::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-19::DEBUG::2014-06-05 09:25:10,818::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n644 bytes (644 B) copied, 0.000339728 s, 1.9 MB/s\n'; <rc> = 0 >Thread-27::DEBUG::2014-06-05 09:25:10,979::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-27::DEBUG::2014-06-05 09:25:10,986::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n363 bytes (363 B) copied, 0.000137045 s, 2.6 MB/s\n'; <rc> = 0 >Thread-32::DEBUG::2014-06-05 09:25:10,999::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-32::DEBUG::2014-06-05 09:25:11,006::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000194248 s, 2.9 MB/s\n'; <rc> = 0 >Thread-21::DEBUG::2014-06-05 09:25:12,515::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-21::DEBUG::2014-06-05 09:25:12,522::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n357 bytes (357 B) copied, 0.000301082 s, 1.2 MB/s\n'; <rc> = 0 >Thread-69045::DEBUG::2014-06-05 09:25:13,834::BindingXMLRPC::1067::vds::(wrapper) client [192.168.11.43]::call vmGetStats with ('803870d2-e365-4ab4-bdcc-4c1d25a03944',) {} >Thread-69045::DEBUG::2014-06-05 09:25:13,835::BindingXMLRPC::1074::vds::(wrapper) return vmGetStats with {'status': {'message': 'Virtual machine does not exist', 'code': 1}} >Thread-69046::DEBUG::2014-06-05 09:25:13,890::BindingXMLRPC::1067::vds::(wrapper) client [192.168.11.43]::call vmMigrationCreate with ({'username': 'Unknown', 'acpiEnable': 'true', 'emulatedMachine': 'pc-1.0', 'afterMigrationStatus': '', 'guestFQDN': '', 'vmId': '803870d2-e365-4ab4-bdcc-4c1d25a03944', 'memGuaranteedSize': 2048, 'transparentHugePages': 'true', 'displaySecurePort': '5901', 'timeOffset': '14279', 'cpuType': 'Nehalem', 'smp': '2', 'migrationDest': 'libvirt', 'custom': {'device_966ade53-ddf1-4699-8061-59f976025a58device_1486a6a3-5a78-4214-a876-44cb899ad8abdevice_d59d8a87-96f1-444a-9c16-91aa8c07aa5ddevice_e254253c-092c-44f9-badc-4feb40a769dcdevice_f85b2abb-2ad2-431b-bf0a-d7ba4e7d763b': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=f85b2abb-2ad2-431b-bf0a-d7ba4e7d763b, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}', 'device_966ade53-ddf1-4699-8061-59f976025a58device_1486a6a3-5a78-4214-a876-44cb899ad8abdevice_d59d8a87-96f1-444a-9c16-91aa8c07aa5d': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=d59d8a87-96f1-444a-9c16-91aa8c07aa5d, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}', 'device_966ade53-ddf1-4699-8061-59f976025a58device_1486a6a3-5a78-4214-a876-44cb899ad8abdevice_d59d8a87-96f1-444a-9c16-91aa8c07aa5ddevice_e254253c-092c-44f9-badc-4feb40a769dc': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=e254253c-092c-44f9-badc-4feb40a769dc, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}', 'device_966ade53-ddf1-4699-8061-59f976025a58': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=966ade53-ddf1-4699-8061-59f976025a58, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}', 'device_966ade53-ddf1-4699-8061-59f976025a58device_1486a6a3-5a78-4214-a876-44cb899ad8ab': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=1486a6a3-5a78-4214-a876-44cb899ad8ab, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}'}, 'vmType': 'kvm', 'spiceSslCipherSuite': 'DEFAULT', '_srcDomXML': "<domain type='kvm' id='33' xmlns:qemu='http://libvirt.org/schemas/domain/qemu/1.0'>\n <name>colvm36</name>\n <uuid>803870d2-e365-4ab4-bdcc-4c1d25a03944</uuid>\n <memory unit='KiB'>3145728</memory>\n <currentMemory unit='KiB'>3145728</currentMemory>\n <memtune>\n <min_guarantee unit='KiB'>2097152</min_guarantee>\n </memtune>\n <vcpu placement='static' current='2'>160</vcpu>\n <cputune>\n <shares>1020</shares>\n </cputune>\n <resource>\n <partition>/machine</partition>\n </resource>\n <sysinfo type='smbios'>\n <system>\n <entry name='manufacturer'>oVirt</entry>\n <entry name='product'>oVirt Node</entry>\n <entry name='version'>20-3</entry>\n <entry name='serial'>49434D53-0200-48D6-3000-D64830004AC9</entry>\n <entry name='uuid'>803870d2-e365-4ab4-bdcc-4c1d25a03944</entry>\n </system>\n </sysinfo>\n <os>\n <type arch='x86_64' machine='pc-1.0'>hvm</type>\n <smbios mode='sysinfo'/>\n </os>\n <features>\n <acpi/>\n </features>\n <cpu mode='custom' match='exact'>\n <model fallback='allow'>Nehalem</model>\n <topology sockets='80' cores='2' threads='1'/>\n </cpu>\n <clock offset='variable' adjustment='7079' basis='utc'>\n <timer name='rtc' tickpolicy='catchup'/>\n </clock>\n <on_poweroff>destroy</on_poweroff>\n <on_reboot>restart</on_reboot>\n <on_crash>destroy</on_crash>\n <devices>\n <emulator>/usr/bin/qemu-kvm</emulator>\n <disk type='file' device='cdrom'>\n <driver name='qemu' type='raw'/>\n <source startupPolicy='optional'/>\n <target dev='hdc' bus='ide'/>\n <readonly/>\n <serial></serial>\n <alias name='ide0-1-0'/>\n <address type='drive' controller='0' bus='1' target='0' unit='0'/>\n </disk>\n <disk type='file' device='disk' snapshot='no'>\n <driver name='qemu' type='raw' cache='none' error_policy='stop' io='threads'/>\n <source file='/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4'>\n <seclabel model='selinux' relabel='yes'/>\n </source>\n <target dev='vda' bus='virtio'/>\n <serial>12843faf-ebbc-4732-b4e9-0bb2501c194f</serial>\n <boot order='1'/>\n <alias name='virtio-disk0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/>\n </disk>\n <controller type='ide' index='0'>\n <alias name='ide0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x1'/>\n </controller>\n <controller type='virtio-serial' index='0'>\n <alias name='virtio-serial0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>\n </controller>\n <controller type='usb' index='0'>\n <alias name='usb0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>\n </controller>\n <controller type='pci' index='0' model='pci-root'>\n <alias name='pci.0'/>\n </controller>\n <interface type='bridge'>\n <mac address='00:0c:29:05:09:1e'/>\n <source bridge='ovirtmgmt'/>\n <target dev='vnet1'/>\n <model type='virtio'/>\n <filterref filter='vdsm-no-mac-spoofing'/>\n <link state='up'/>\n <alias name='net0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>\n </interface>\n <channel type='unix'>\n <source mode='bind' path='/var/lib/libvirt/qemu/channels/803870d2-e365-4ab4-bdcc-4c1d25a03944.com.redhat.rhevm.vdsm'/>\n <target type='virtio' name='com.redhat.rhevm.vdsm'/>\n <alias name='channel0'/>\n <address type='virtio-serial' controller='0' bus='0' port='1'/>\n </channel>\n <channel type='unix'>\n <source mode='bind' path='/var/lib/libvirt/qemu/channels/803870d2-e365-4ab4-bdcc-4c1d25a03944.org.qemu.guest_agent.0'/>\n <target type='virtio' name='org.qemu.guest_agent.0'/>\n <alias name='channel1'/>\n <address type='virtio-serial' controller='0' bus='0' port='2'/>\n </channel>\n <channel type='spicevmc'>\n <target type='virtio' name='com.redhat.spice.0'/>\n <alias name='channel2'/>\n <address type='virtio-serial' controller='0' bus='0' port='3'/>\n </channel>\n <input type='mouse' bus='ps2'/>\n <graphics type='spice' tlsPort='5901' autoport='yes' keymap='en-us' passwdValidTo='2014-06-04T18:59:11' connected='keep'>\n <listen type='network' address='192.168.11.43' network='vdsm-ovirtmgmt'/>\n <channel name='main' mode='secure'/>\n <channel name='display' mode='secure'/>\n <channel name='inputs' mode='secure'/>\n <channel name='cursor' mode='secure'/>\n <channel name='playback' mode='secure'/>\n <channel name='record' mode='secure'/>\n <channel name='smartcard' mode='secure'/>\n <channel name='usbredir' mode='secure'/>\n </graphics>\n <sound model='ac97'>\n <alias name='sound0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>\n </sound>\n <video>\n <model type='qxl' ram='65536' vram='32768' heads='1'/>\n <alias name='video0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>\n </video>\n <memballoon model='virtio'>\n <alias name='balloon0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x07' function='0x0'/>\n </memballoon>\n </devices>\n <seclabel type='dynamic' model='selinux' relabel='yes'>\n <label>system_u:system_r:svirt_t:s0:c810,c980</label>\n <imagelabel>system_u:object_r:svirt_image_t:s0:c810,c980</imagelabel>\n </seclabel>\n <qemu:commandline>\n <qemu:env name='SPICE_DEBUG_ALLOW_MC' value='1'/>\n <qemu:env name='SPICE_DEBUG_LEVEL' value='4'/>\n </qemu:commandline>\n</domain>\n", 'memSize': 3072, 'elapsedTimeOffset': 63914.31065106392, 'vmName': 'colvm36', 'nice': '0', 'status': 'Up', 'clientIp': '', 'displayIp': '192.168.11.43', 'displayPort': '-1', 'smpCoresPerSocket': '2', 'smartcardEnable': 'false', 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 'nicModel': 'rtl8139,pv', 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'displayNetwork': 'ovirtmgmt', 'devices': [{'specParams': {}, 'alias': 'sound0', 'deviceId': '70e43d5b-6119-4204-a138-ef9a30dcb920', 'address': {'slot': '0x04', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'ac97', 'type': 'sound'}, {'target': 3145728, 'specParams': {'model': 'virtio'}, 'alias': 'balloon0', 'deviceId': '08fb1420-af65-452e-ab83-847a96a5090d', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'memballoon', 'type': 'balloon'}, {'device': 'unix', 'alias': 'channel0', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '1'}}, {'device': 'unix', 'alias': 'channel1', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '2'}}, {'device': 'spicevmc', 'alias': 'channel2', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '3'}}, {'device': 'usb', 'alias': 'usb0', 'type': 'controller', 'address': {'slot': '0x01', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x2'}}, {'device': 'ide', 'alias': 'ide0', 'type': 'controller', 'address': {'slot': '0x01', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x1'}}, {'device': 'virtio-serial', 'alias': 'virtio-serial0', 'type': 'controller', 'address': {'slot': '0x05', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}}, {'specParams': {'vram': '32768', 'heads': '1'}, 'alias': 'video0', 'deviceId': '5ee02b8e-5916-4fce-89aa-ed26b2f939b5', 'address': {'slot': '0x02', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'qxl', 'type': 'video'}, {'nicModel': 'pv', 'macAddr': '00:0c:29:05:09:1e', 'linkActive': True, 'network': 'ovirtmgmt', 'specParams': {}, 'filter': 'vdsm-no-mac-spoofing', 'alias': 'net0', 'deviceId': '27b080c4-a9d0-479a-b0fe-de197c80af60', 'address': {'slot': '0x03', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'bridge', 'type': 'interface', 'name': 'vnet1'}, {'index': '2', 'iface': 'ide', 'name': 'hdc', 'alias': 'ide0-1-0', 'specParams': {'path': ''}, 'readonly': 'True', 'deviceId': '6c0d02e8-d3ef-4b64-a5ab-74ebfbe9ea5e', 'address': {'bus': '1', 'controller': '0', 'type': 'drive', 'target': '0', 'unit': '0'}, 'device': 'cdrom', 'shared': 'false', 'path': '', 'type': 'disk'}, {'address': {'slot': '0x06', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'reqsize': '0', 'index': 0, 'iface': 'virtio', 'apparentsize': '26863764480', 'specParams': {}, 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f', 'readonly': 'False', 'shared': 'false', 'truesize': '27380420608', 'type': 'disk', 'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volumeInfo': {'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volType': 'path', 'leaseOffset': 0, 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'leasePath': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4.lease', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f', 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4'}, 'format': 'raw', 'deviceId': '12843faf-ebbc-4732-b4e9-0bb2501c194f', 'poolID': '94ed7a19-fade-4bd6-83f2-2cbb2f730b95', 'device': 'disk', 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'propagateErrors': 'off', 'optional': 'false', 'name': 'vda', 'bootOrder': '1', 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'alias': 'virtio-disk0', 'volumeChain': [{'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volType': 'path', 'leaseOffset': 0, 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'leasePath': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4.lease', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f', 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4'}]}], 'maxVCpus': '160', 'guestIPs': '', 'display': 'qxl'},) {} >Thread-69046::DEBUG::2014-06-05 09:25:13,890::API::523::vds::(migrationCreate) Migration create >Thread-69046::INFO::2014-06-05 09:25:13,896::clientIF::366::vds::(createVm) vmContainerLock acquired by vm 803870d2-e365-4ab4-bdcc-4c1d25a03944 >Thread-69047::DEBUG::2014-06-05 09:25:13,901::vm::2238::vm.Vm::(_startUnderlyingVm) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Start >Thread-69046::DEBUG::2014-06-05 09:25:13,901::clientIF::379::vds::(createVm) Total desktops after creation of 803870d2-e365-4ab4-bdcc-4c1d25a03944 is 1 >Thread-69047::DEBUG::2014-06-05 09:25:13,901::vm::2242::vm.Vm::(_startUnderlyingVm) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::_ongoingCreations acquired >Thread-69046::DEBUG::2014-06-05 09:25:13,901::vm::5236::vm.Vm::(waitForMigrationDestinationPrepare) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::migration destination: waiting for VM creation >Thread-69047::INFO::2014-06-05 09:25:13,901::vm::3112::vm.Vm::(_run) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::VM wrapper has started >Thread-69046::DEBUG::2014-06-05 09:25:13,902::vm::5241::vm.Vm::(waitForMigrationDestinationPrepare) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::migration destination: waiting 36s for path preparation >Thread-69047::WARNING::2014-06-05 09:25:13,902::vm::2058::vm.Vm::(buildConfDevices) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Unknown type found, device: '{'device': 'unix', 'alias': 'channel0', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '1'}}' found >Thread-69047::WARNING::2014-06-05 09:25:13,902::vm::2058::vm.Vm::(buildConfDevices) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Unknown type found, device: '{'device': 'unix', 'alias': 'channel1', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '2'}}' found >Thread-69047::WARNING::2014-06-05 09:25:13,903::vm::2058::vm.Vm::(buildConfDevices) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Unknown type found, device: '{'device': 'spicevmc', 'alias': 'channel2', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '3'}}' found >Thread-69047::DEBUG::2014-06-05 09:25:13,903::task::595::TaskManager.Task::(_updateState) Task=`f8a2bcee-962b-4839-82f3-0ef0438664f1`::moving from state init -> state preparing >Thread-69047::INFO::2014-06-05 09:25:13,903::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='272ec473-6041-42ee-bd1a-732789dd18d4', spUUID='94ed7a19-fade-4bd6-83f2-2cbb2f730b95', imgUUID='12843faf-ebbc-4732-b4e9-0bb2501c194f', volUUID='04b45378-e7b8-4488-b48a-6b3fac1f18a4', options=None) >Thread-69047::INFO::2014-06-05 09:25:13,905::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '27380420608', 'apparentsize': '26863764480'} >Thread-69047::DEBUG::2014-06-05 09:25:13,905::task::1185::TaskManager.Task::(prepare) Task=`f8a2bcee-962b-4839-82f3-0ef0438664f1`::finished: {'truesize': '27380420608', 'apparentsize': '26863764480'} >Thread-69047::DEBUG::2014-06-05 09:25:13,905::task::595::TaskManager.Task::(_updateState) Task=`f8a2bcee-962b-4839-82f3-0ef0438664f1`::moving from state preparing -> state finished >Thread-69047::DEBUG::2014-06-05 09:25:13,905::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-69047::DEBUG::2014-06-05 09:25:13,905::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-69047::DEBUG::2014-06-05 09:25:13,905::task::990::TaskManager.Task::(_decref) Task=`f8a2bcee-962b-4839-82f3-0ef0438664f1`::ref 0 aborting False >Thread-69047::INFO::2014-06-05 09:25:13,906::clientIF::324::vds::(prepareVolumePath) prepared volume path: >Thread-69047::DEBUG::2014-06-05 09:25:13,906::task::595::TaskManager.Task::(_updateState) Task=`5d3d4cc9-acbc-40fb-b1c6-2aa99ed83731`::moving from state init -> state preparing >Thread-69047::INFO::2014-06-05 09:25:13,906::logUtils::44::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='272ec473-6041-42ee-bd1a-732789dd18d4', spUUID='94ed7a19-fade-4bd6-83f2-2cbb2f730b95', imgUUID='12843faf-ebbc-4732-b4e9-0bb2501c194f', leafUUID='04b45378-e7b8-4488-b48a-6b3fac1f18a4') >Thread-69047::DEBUG::2014-06-05 09:25:13,906::resourceManager::198::ResourceManager.Request::(__init__) ResName=`Storage.272ec473-6041-42ee-bd1a-732789dd18d4`ReqID=`8e996383-3b0b-4d66-9d85-deb5e9ee620c`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3238' at 'prepareImage' >Thread-69047::DEBUG::2014-06-05 09:25:13,907::resourceManager::542::ResourceManager::(registerResource) Trying to register resource 'Storage.272ec473-6041-42ee-bd1a-732789dd18d4' for lock type 'shared' >Thread-69047::DEBUG::2014-06-05 09:25:13,907::resourceManager::601::ResourceManager::(registerResource) Resource 'Storage.272ec473-6041-42ee-bd1a-732789dd18d4' is free. Now locking as 'shared' (1 active user) >Thread-69047::DEBUG::2014-06-05 09:25:13,907::resourceManager::238::ResourceManager.Request::(grant) ResName=`Storage.272ec473-6041-42ee-bd1a-732789dd18d4`ReqID=`8e996383-3b0b-4d66-9d85-deb5e9ee620c`::Granted request >Thread-69047::DEBUG::2014-06-05 09:25:13,907::task::827::TaskManager.Task::(resourceAcquired) Task=`5d3d4cc9-acbc-40fb-b1c6-2aa99ed83731`::_resourcesAcquired: Storage.272ec473-6041-42ee-bd1a-732789dd18d4 (shared) >Thread-69047::DEBUG::2014-06-05 09:25:13,907::task::990::TaskManager.Task::(_decref) Task=`5d3d4cc9-acbc-40fb-b1c6-2aa99ed83731`::ref 1 aborting False >Thread-69047::WARNING::2014-06-05 09:25:13,909::fileUtils::167::Storage.fileUtils::(createdir) Dir /var/run/vdsm/storage/272ec473-6041-42ee-bd1a-732789dd18d4 already exists >Thread-69047::DEBUG::2014-06-05 09:25:13,909::fileSD::480::Storage.StorageDomain::(createImageLinks) img run dir already exists: /var/run/vdsm/storage/272ec473-6041-42ee-bd1a-732789dd18d4/12843faf-ebbc-4732-b4e9-0bb2501c194f >Thread-69047::DEBUG::2014-06-05 09:25:13,910::fileVolume::529::Storage.Volume::(validateVolumePath) validate path for 04b45378-e7b8-4488-b48a-6b3fac1f18a4 >Thread-69047::INFO::2014-06-05 09:25:13,912::logUtils::47::dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'info': {'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'leasePath': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4.lease', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f'}, 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'imgVolumesInfo': [{'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'leasePath': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4.lease', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f'}]} >Thread-69047::DEBUG::2014-06-05 09:25:13,912::task::1185::TaskManager.Task::(prepare) Task=`5d3d4cc9-acbc-40fb-b1c6-2aa99ed83731`::finished: {'info': {'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'leasePath': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4.lease', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f'}, 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'imgVolumesInfo': [{'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'leasePath': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4.lease', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f'}]} >Thread-69047::DEBUG::2014-06-05 09:25:13,912::task::595::TaskManager.Task::(_updateState) Task=`5d3d4cc9-acbc-40fb-b1c6-2aa99ed83731`::moving from state preparing -> state finished >Thread-69047::DEBUG::2014-06-05 09:25:13,912::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.272ec473-6041-42ee-bd1a-732789dd18d4': < ResourceRef 'Storage.272ec473-6041-42ee-bd1a-732789dd18d4', isValid: 'True' obj: 'None'>} >Thread-69047::DEBUG::2014-06-05 09:25:13,912::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-69047::DEBUG::2014-06-05 09:25:13,912::resourceManager::616::ResourceManager::(releaseResource) Trying to release resource 'Storage.272ec473-6041-42ee-bd1a-732789dd18d4' >Thread-69047::DEBUG::2014-06-05 09:25:13,913::resourceManager::635::ResourceManager::(releaseResource) Released resource 'Storage.272ec473-6041-42ee-bd1a-732789dd18d4' (0 active users) >Thread-69047::DEBUG::2014-06-05 09:25:13,913::resourceManager::641::ResourceManager::(releaseResource) Resource 'Storage.272ec473-6041-42ee-bd1a-732789dd18d4' is free, finding out if anyone is waiting for it. >Thread-69047::DEBUG::2014-06-05 09:25:13,913::resourceManager::649::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.272ec473-6041-42ee-bd1a-732789dd18d4', Clearing records. >Thread-69047::DEBUG::2014-06-05 09:25:13,913::task::990::TaskManager.Task::(_decref) Task=`5d3d4cc9-acbc-40fb-b1c6-2aa99ed83731`::ref 0 aborting False >Thread-69047::INFO::2014-06-05 09:25:13,913::clientIF::324::vds::(prepareVolumePath) prepared volume path: /rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4 >Thread-69047::DEBUG::2014-06-05 09:25:13,917::vm::2259::vm.Vm::(_startUnderlyingVm) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::_ongoingCreations released >Thread-69047::DEBUG::2014-06-05 09:25:13,924::vm::3697::vm.Vm::(_waitForIncomingMigrationFinish) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Waiting 21600 seconds for end of migration >Thread-69046::DEBUG::2014-06-05 09:25:13,925::API::536::vds::(migrationCreate) Destination VM creation succeeded >Thread-69046::DEBUG::2014-06-05 09:25:13,925::BindingXMLRPC::1074::vds::(wrapper) return vmMigrationCreate with {'status': {'message': 'Done', 'code': 0}, 'migrationPort': 0, 'params': {'guestFQDN': '', 'acpiEnable': 'true', 'emulatedMachine': 'pc-1.0', 'afterMigrationStatus': '', 'pid': '0', 'memGuaranteedSize': 2048, 'transparentHugePages': 'true', 'displaySecurePort': '-1', 'timeOffset': '14279', 'cpuType': 'Nehalem', 'custom': {'device_966ade53-ddf1-4699-8061-59f976025a58device_1486a6a3-5a78-4214-a876-44cb899ad8abdevice_d59d8a87-96f1-444a-9c16-91aa8c07aa5ddevice_e254253c-092c-44f9-badc-4feb40a769dcdevice_f85b2abb-2ad2-431b-bf0a-d7ba4e7d763b': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=f85b2abb-2ad2-431b-bf0a-d7ba4e7d763b, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}', 'device_966ade53-ddf1-4699-8061-59f976025a58device_1486a6a3-5a78-4214-a876-44cb899ad8abdevice_d59d8a87-96f1-444a-9c16-91aa8c07aa5d': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=d59d8a87-96f1-444a-9c16-91aa8c07aa5d, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}', 'device_966ade53-ddf1-4699-8061-59f976025a58device_1486a6a3-5a78-4214-a876-44cb899ad8abdevice_d59d8a87-96f1-444a-9c16-91aa8c07aa5ddevice_e254253c-092c-44f9-badc-4feb40a769dc': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=e254253c-092c-44f9-badc-4feb40a769dc, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}', 'device_966ade53-ddf1-4699-8061-59f976025a58': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=966ade53-ddf1-4699-8061-59f976025a58, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}', 'device_966ade53-ddf1-4699-8061-59f976025a58device_1486a6a3-5a78-4214-a876-44cb899ad8ab': 'VmDevice {vmId=803870d2-e365-4ab4-bdcc-4c1d25a03944, deviceId=1486a6a3-5a78-4214-a876-44cb899ad8ab, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}'}, 'migrationDest': 'libvirt', 'smp': '2', 'vmType': 'kvm', 'spiceSslCipherSuite': 'DEFAULT', 'memSize': 3072, 'vmName': 'colvm36', 'nice': '0', 'username': 'Unknown', 'vmId': '803870d2-e365-4ab4-bdcc-4c1d25a03944', 'displayIp': '192.168.11.42', 'keyboardLayout': 'en-us', 'displayPort': '-1', 'guestIPs': '', 'smartcardEnable': 'false', 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 'nicModel': 'rtl8139,pv', 'smpCoresPerSocket': '2', 'kvmEnable': 'true', 'displayNetwork': 'ovirtmgmt', 'devices': [{'specParams': {}, 'alias': 'sound0', 'deviceId': '70e43d5b-6119-4204-a138-ef9a30dcb920', 'address': {'slot': '0x04', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'ac97', 'type': 'sound'}, {'target': 3145728, 'specParams': {'model': 'virtio'}, 'alias': 'balloon0', 'deviceId': '08fb1420-af65-452e-ab83-847a96a5090d', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'memballoon', 'type': 'balloon'}, {'device': 'unix', 'alias': 'channel0', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '1'}}, {'device': 'unix', 'alias': 'channel1', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '2'}}, {'device': 'spicevmc', 'alias': 'channel2', 'type': 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '3'}}, {'device': 'usb', 'alias': 'usb0', 'type': 'controller', 'address': {'slot': '0x01', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x2'}}, {'device': 'ide', 'alias': 'ide0', 'type': 'controller', 'address': {'slot': '0x01', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x1'}}, {'device': 'virtio-serial', 'alias': 'virtio-serial0', 'type': 'controller', 'address': {'slot': '0x05', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}}, {'specParams': {'vram': '32768', 'heads': '1'}, 'alias': 'video0', 'deviceId': '5ee02b8e-5916-4fce-89aa-ed26b2f939b5', 'address': {'slot': '0x02', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'qxl', 'type': 'video'}, {'nicModel': 'pv', 'macAddr': '00:0c:29:05:09:1e', 'linkActive': True, 'network': 'ovirtmgmt', 'specParams': {}, 'filter': 'vdsm-no-mac-spoofing', 'alias': 'net0', 'deviceId': '27b080c4-a9d0-479a-b0fe-de197c80af60', 'address': {'slot': '0x03', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'bridge', 'type': 'interface', 'name': 'vnet1'}, {'index': '2', 'iface': 'ide', 'name': 'hdc', 'alias': 'ide0-1-0', 'specParams': {'path': ''}, 'readonly': 'True', 'deviceId': '6c0d02e8-d3ef-4b64-a5ab-74ebfbe9ea5e', 'address': {'bus': '1', 'controller': '0', 'type': 'drive', 'target': '0', 'unit': '0'}, 'device': 'cdrom', 'shared': 'false', 'path': '', 'type': 'disk'}, {'address': {'slot': '0x06', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'reqsize': '0', 'index': 0, 'iface': 'virtio', 'apparentsize': '26863764480', 'specParams': {}, 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f', 'readonly': 'False', 'shared': 'false', 'truesize': '27380420608', 'type': 'disk', 'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volumeInfo': {'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'leasePath': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4.lease', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f'}, 'format': 'raw', 'deviceId': '12843faf-ebbc-4732-b4e9-0bb2501c194f', 'poolID': '94ed7a19-fade-4bd6-83f2-2cbb2f730b95', 'device': 'disk', 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'propagateErrors': 'off', 'optional': 'false', 'name': 'vda', 'bootOrder': '1', 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'alias': 'virtio-disk0', 'volumeChain': [{'domainID': '272ec473-6041-42ee-bd1a-732789dd18d4', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'volumeID': '04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'leasePath': '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4.lease', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f'}]}], 'status': 'Migration Destination', 'maxVCpus': '160', 'clientIp': '', 'display': 'qxl'}} >libvirtEventLoop::DEBUG::2014-06-05 09:25:14,410::vm::5151::vm.Vm::(_onLibvirtLifecycleEvent) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::event Started detail 1 opaque None >Thread-63529::DEBUG::2014-06-05 09:25:15,399::BindingXMLRPC::1067::vds::(wrapper) client [192.168.11.2]::call vmGetStats with ('803870d2-e365-4ab4-bdcc-4c1d25a03944',) {} flowID [160ca2e5] >Thread-63529::DEBUG::2014-06-05 09:25:15,400::BindingXMLRPC::1074::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Migration Destination', 'hash': '0', 'acpiEnable': 'true', 'pid': '0', 'displayIp': '192.168.11.42', 'displayPort': '-1', 'displaySecurePort': '-1', 'timeOffset': '14279', 'kvmEnable': 'true', 'network': {}, 'vmId': '803870d2-e365-4ab4-bdcc-4c1d25a03944', 'displayType': 'qxl', 'disks': {}, 'monitorResponse': '0', 'elapsedTime': '63915', 'vmType': 'kvm', 'clientIp': ''}]} >Thread-20::DEBUG::2014-06-05 09:25:18,086::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-20::DEBUG::2014-06-05 09:25:18,093::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000296059 s, 1.9 MB/s\n'; <rc> = 0 >Thread-63529::DEBUG::2014-06-05 09:25:18,431::BindingXMLRPC::1067::vds::(wrapper) client [192.168.11.2]::call vmGetStats with ('803870d2-e365-4ab4-bdcc-4c1d25a03944',) {} flowID [619d876a] >Thread-63529::DEBUG::2014-06-05 09:25:18,432::BindingXMLRPC::1074::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Migration Destination', 'hash': '0', 'acpiEnable': 'true', 'pid': '0', 'displayIp': '192.168.11.42', 'displayPort': '-1', 'displaySecurePort': '-1', 'timeOffset': '14279', 'kvmEnable': 'true', 'network': {}, 'vmId': '803870d2-e365-4ab4-bdcc-4c1d25a03944', 'displayType': 'qxl', 'disks': {}, 'monitorResponse': '0', 'elapsedTime': '63918', 'vmType': 'kvm', 'clientIp': ''}]} >libvirtEventLoop::DEBUG::2014-06-05 09:25:20,126::vm::5151::vm.Vm::(_onLibvirtLifecycleEvent) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::event Resumed detail 0 opaque None >libvirtEventLoop::DEBUG::2014-06-05 09:25:20,127::vm::5151::vm.Vm::(_onLibvirtLifecycleEvent) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::event Resumed detail 1 opaque None >Thread-69047::DEBUG::2014-06-05 09:25:20,150::vm::5007::vm.Vm::(_getUnderlyingDriveInfo) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Looking for drive with attributes {'name': u'hdc', 'bootOrder': '', 'boot': [], 'readonly': True, 'address': {u'bus': u'1', u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'}, 'path': '', 'type': u'cdrom'} >Thread-69047::DEBUG::2014-06-05 09:25:20,150::vm::5028::vm.Vm::(_getUnderlyingDriveInfo) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Matched {'name': (u'hdc', u'hdc'), 'bootOrder': ('', None), 'boot': ([], None), 'readonly': (True, True), 'address': ({u'bus': u'1', u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'}, {u'bus': u'1', u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'}), 'path': ('', ''), 'type': (u'cdrom', u'cdrom')} >Thread-69047::DEBUG::2014-06-05 09:25:20,150::vm::5047::vm.Vm::(_getUnderlyingDriveInfo) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Matched {'name': (u'hdc', u'hdc'), 'bootOrder': ('', None), 'boot': ([], None), 'readonly': (True, 'True'), 'address': ({u'bus': u'1', u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'}, {u'bus': u'1', u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'}), 'path': ('', ''), 'type': (u'cdrom', 'disk')} >Thread-69047::DEBUG::2014-06-05 09:25:20,150::vm::5007::vm.Vm::(_getUnderlyingDriveInfo) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Looking for drive with attributes {'name': u'vda', 'bootOrder': u'1', 'boot': [<DOM Element: boot at 0x7f1658204c68>], 'readonly': False, 'address': {u'slot': u'0x06', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}, 'path': u'/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', 'type': u'disk'} >Thread-69047::DEBUG::2014-06-05 09:25:20,151::vm::5028::vm.Vm::(_getUnderlyingDriveInfo) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Matched {'name': (u'vda', u'vda'), 'bootOrder': (u'1', u'1'), 'boot': ([<DOM Element: boot at 0x7f1658204c68>], None), 'readonly': (False, False), 'address': ({u'slot': u'0x06', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}, {u'slot': u'0x06', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}), 'path': (u'/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4'), 'type': (u'disk', u'disk')} >Thread-69047::DEBUG::2014-06-05 09:25:20,151::vm::5047::vm.Vm::(_getUnderlyingDriveInfo) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Matched {'name': (u'vda', u'vda'), 'bootOrder': (u'1', u'1'), 'boot': ([<DOM Element: boot at 0x7f1658204c68>], None), 'readonly': (False, 'False'), 'address': ({u'slot': u'0x06', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}, {u'slot': u'0x06', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x0'}), 'path': (u'/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4', '/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/images/12843faf-ebbc-4732-b4e9-0bb2501c194f/04b45378-e7b8-4488-b48a-6b3fac1f18a4'), 'type': (u'disk', 'disk')} >Thread-69047::DEBUG::2014-06-05 09:25:20,216::sampling::285::vm.Vm::(start) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Start statistics collection >Thread-69049::DEBUG::2014-06-05 09:25:20,217::sampling::314::vm.Vm::(run) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Stats thread started >Thread-69049::DEBUG::2014-06-05 09:25:20,218::task::595::TaskManager.Task::(_updateState) Task=`cb4c6e7f-1e87-42d2-bd58-ac906d3bbdce`::moving from state init -> state preparing >Thread-69049::INFO::2014-06-05 09:25:20,218::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='272ec473-6041-42ee-bd1a-732789dd18d4', spUUID='94ed7a19-fade-4bd6-83f2-2cbb2f730b95', imgUUID='12843faf-ebbc-4732-b4e9-0bb2501c194f', volUUID='04b45378-e7b8-4488-b48a-6b3fac1f18a4', options=None) >Thread-69049::INFO::2014-06-05 09:25:20,220::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '27380420608', 'apparentsize': '26863764480'} >Thread-69047::DEBUG::2014-06-05 09:25:20,220::vmChannels::194::vds::(register) Add fileno 27 to listener's channels. >Thread-69049::DEBUG::2014-06-05 09:25:20,220::task::1185::TaskManager.Task::(prepare) Task=`cb4c6e7f-1e87-42d2-bd58-ac906d3bbdce`::finished: {'truesize': '27380420608', 'apparentsize': '26863764480'} >Thread-69049::DEBUG::2014-06-05 09:25:20,220::task::595::TaskManager.Task::(_updateState) Task=`cb4c6e7f-1e87-42d2-bd58-ac906d3bbdce`::moving from state preparing -> state finished >Thread-69049::DEBUG::2014-06-05 09:25:20,221::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-69049::DEBUG::2014-06-05 09:25:20,221::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-69049::DEBUG::2014-06-05 09:25:20,221::task::990::TaskManager.Task::(_decref) Task=`cb4c6e7f-1e87-42d2-bd58-ac906d3bbdce`::ref 0 aborting False >Thread-69047::DEBUG::2014-06-05 09:25:20,239::vm::3744::vm.Vm::(_waitForIncomingMigrationFinish) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::End of migration >VM Channels Listener::DEBUG::2014-06-05 09:25:20,821::vmChannels::102::vds::(_do_add_channels) fileno 27 was added to unconnected channels. >VM Channels Listener::DEBUG::2014-06-05 09:25:20,821::vmChannels::128::vds::(_handle_unconnected) Trying to connect fileno 27. >VM Channels Listener::DEBUG::2014-06-05 09:25:20,822::guestIF::194::vm.Vm::(_connect) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Attempting connection to /var/lib/libvirt/qemu/channels/803870d2-e365-4ab4-bdcc-4c1d25a03944.com.redhat.rhevm.vdsm >VM Channels Listener::DEBUG::2014-06-05 09:25:20,822::guestIF::197::vm.Vm::(_connect) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Connected to /var/lib/libvirt/qemu/channels/803870d2-e365-4ab4-bdcc-4c1d25a03944.com.redhat.rhevm.vdsm >VM Channels Listener::DEBUG::2014-06-05 09:25:20,822::vmChannels::144::vds::(_handle_unconnected) Connecting to fileno 27 succeeded. >Thread-19::DEBUG::2014-06-05 09:25:20,832::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-19::DEBUG::2014-06-05 09:25:20,840::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n644 bytes (644 B) copied, 0.000209395 s, 3.1 MB/s\n'; <rc> = 0 >Thread-27::DEBUG::2014-06-05 09:25:20,999::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-27::DEBUG::2014-06-05 09:25:21,007::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n363 bytes (363 B) copied, 0.000240446 s, 1.5 MB/s\n'; <rc> = 0 >Thread-32::DEBUG::2014-06-05 09:25:21,020::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-32::DEBUG::2014-06-05 09:25:21,028::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000241353 s, 2.3 MB/s\n'; <rc> = 0 >Thread-63529::DEBUG::2014-06-05 09:25:21,461::BindingXMLRPC::1067::vds::(wrapper) client [192.168.11.2]::call vmGetStats with ('803870d2-e365-4ab4-bdcc-4c1d25a03944',) {} flowID [638a3b4c] >Thread-63529::DEBUG::2014-06-05 09:25:21,462::vm::587::vm.Vm::(_getCpuStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::CPU stats not available: 'NoneType' object has no attribute '__getitem__' >Thread-63529::DEBUG::2014-06-05 09:25:21,462::vm::623::vm.Vm::(_getNetworkStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Network stats not available >Thread-63529::DEBUG::2014-06-05 09:25:21,462::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >Thread-63529::DEBUG::2014-06-05 09:25:21,462::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >Thread-63529::DEBUG::2014-06-05 09:25:21,462::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >Thread-63529::DEBUG::2014-06-05 09:25:21,463::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >Thread-63529::DEBUG::2014-06-05 09:25:21,464::BindingXMLRPC::1074::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Up', 'username': 'Unknown', 'memUsage': '0', 'acpiEnable': 'true', 'guestFQDN': '', 'pid': '5002', 'displayIp': '192.168.11.42', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'5900', 'timeOffset': '14279', 'hash': '-2832807100151321570', 'balloonInfo': {'balloon_max': '3145728', 'balloon_target': '3145728', 'balloon_cur': '3145728', 'balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network': {u'vnet0': {'state': 'unknown', 'macAddr': '00:0c:29:05:09:1e', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': '803870d2-e365-4ab4-bdcc-4c1d25a03944', 'displayType': 'qxl', 'cpuUser': '0.00', 'disks': {u'vda': {'truesize': '27380420608', 'apparentsize': '26863764480', 'imageID': '12843faf-ebbc-4732-b4e9-0bb2501c194f'}, u'hdc': {'truesize': '0', 'apparentsize': '0'}}, 'monitorResponse': '0', 'statsAge': '1.24', 'elapsedTime': '63921', 'vmType': 'kvm', 'cpuSys': '0.00', 'guestCPUCount': -1, 'appsList': [], 'guestIPs': ''}]} >Thread-21::DEBUG::2014-06-05 09:25:22,532::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-21::DEBUG::2014-06-05 09:25:22,539::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n357 bytes (357 B) copied, 0.000244986 s, 1.5 MB/s\n'; <rc> = 0 >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,287::vm::587::vm.Vm::(_getCpuStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::CPU stats not available: 'NoneType' object has no attribute '__getitem__' >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,287::vm::623::vm.Vm::(_getNetworkStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Network stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,288::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,288::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,288::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,288::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,290::vm::587::vm.Vm::(_getCpuStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::CPU stats not available: 'NoneType' object has no attribute '__getitem__' >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,290::vm::623::vm.Vm::(_getNetworkStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Network stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,290::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,290::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,290::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:23,291::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >Thread-63529::DEBUG::2014-06-05 09:25:24,578::task::595::TaskManager.Task::(_updateState) Task=`600e4f4d-d996-485d-9936-dc89e6936a39`::moving from state init -> state preparing >Thread-63529::INFO::2014-06-05 09:25:24,578::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) >Thread-63529::INFO::2014-06-05 09:25:24,579::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-8215-e15f55f66906': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000209395', 'lastCheck': '3.7', 'valid': True}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000296059', 'lastCheck': '6.5', 'valid': True}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000244986', 'lastCheck': '2.0', 'valid': True}, '63041fa9-e093-4b44-b36f-f39f16d3974f': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000240446', 'lastCheck': '3.6', 'valid': True}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000241353', 'lastCheck': '3.5', 'valid': True}} >Thread-63529::DEBUG::2014-06-05 09:25:24,579::task::1185::TaskManager.Task::(prepare) Task=`600e4f4d-d996-485d-9936-dc89e6936a39`::finished: {'2c51d320-88ce-4f23-8215-e15f55f66906': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000209395', 'lastCheck': '3.7', 'valid': True}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000296059', 'lastCheck': '6.5', 'valid': True}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000244986', 'lastCheck': '2.0', 'valid': True}, '63041fa9-e093-4b44-b36f-f39f16d3974f': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000240446', 'lastCheck': '3.6', 'valid': True}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000241353', 'lastCheck': '3.5', 'valid': True}} >Thread-63529::DEBUG::2014-06-05 09:25:24,579::task::595::TaskManager.Task::(_updateState) Task=`600e4f4d-d996-485d-9936-dc89e6936a39`::moving from state preparing -> state finished >Thread-63529::DEBUG::2014-06-05 09:25:24,579::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-63529::DEBUG::2014-06-05 09:25:24,579::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-63529::DEBUG::2014-06-05 09:25:24,580::task::990::TaskManager.Task::(_decref) Task=`600e4f4d-d996-485d-9936-dc89e6936a39`::ref 0 aborting False >Thread-63529::DEBUG::2014-06-05 09:25:24,619::vm::587::vm.Vm::(_getCpuStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::CPU stats not available: 'NoneType' object has no attribute '__getitem__' >Thread-63529::DEBUG::2014-06-05 09:25:24,619::vm::623::vm.Vm::(_getNetworkStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Network stats not available >Thread-63529::DEBUG::2014-06-05 09:25:24,619::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >Thread-63529::DEBUG::2014-06-05 09:25:24,619::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >Thread-63529::DEBUG::2014-06-05 09:25:24,619::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >Thread-63529::DEBUG::2014-06-05 09:25:24,619::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >Thread-63529::DEBUG::2014-06-05 09:25:26,066::BindingXMLRPC::1067::vds::(wrapper) client [192.168.11.2]::call vmSetTicket with ('803870d2-e365-4ab4-bdcc-4c1d25a03944', 'gJieYGoA6mDb', '120', 'disconnect', {'userName': 'Stockhausen', 'userId': 'b6b1f9f8-7030-4ea6-9653-9345860d58a9'}) {} flowID [62bb6fba] >Thread-63529::DEBUG::2014-06-05 09:25:26,080::BindingXMLRPC::1074::vds::(wrapper) return vmSetTicket with {'status': {'message': 'Done', 'code': 0}} >Thread-20::DEBUG::2014-06-05 09:25:28,105::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-20::DEBUG::2014-06-05 09:25:28,113::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000276277 s, 2.0 MB/s\n'; <rc> = 0 >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,297::vm::587::vm.Vm::(_getCpuStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::CPU stats not available: 'NoneType' object has no attribute '__getitem__' >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,297::vm::623::vm.Vm::(_getNetworkStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Network stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,297::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,298::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,298::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,298::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,299::vm::587::vm.Vm::(_getCpuStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::CPU stats not available: 'NoneType' object has no attribute '__getitem__' >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,300::vm::623::vm.Vm::(_getNetworkStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Network stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,300::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,300::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,300::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:28,300::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >Thread-19::DEBUG::2014-06-05 09:25:30,853::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-19::DEBUG::2014-06-05 09:25:30,860::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n644 bytes (644 B) copied, 0.000216338 s, 3.0 MB/s\n'; <rc> = 0 >Thread-27::DEBUG::2014-06-05 09:25:31,020::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-27::DEBUG::2014-06-05 09:25:31,028::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n363 bytes (363 B) copied, 0.000282369 s, 1.3 MB/s\n'; <rc> = 0 >Thread-32::DEBUG::2014-06-05 09:25:31,040::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-32::DEBUG::2014-06-05 09:25:31,047::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000206051 s, 2.7 MB/s\n'; <rc> = 0 >libvirtEventLoop::DEBUG::2014-06-05 09:25:32,342::clientIF::555::vm.Vm::(dispatchLibvirtEvents) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::graphics event phase 0 localAddr {'node': '192.168.11.42', 'service': '', 'family': 0} remoteAddr {'node': '192.168.10.181', 'service': '', 'family': 0}authScheme subject [] >Thread-21::DEBUG::2014-06-05 09:25:32,548::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-21::DEBUG::2014-06-05 09:25:32,556::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n357 bytes (357 B) copied, 0.000283246 s, 1.3 MB/s\n'; <rc> = 0 >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,307::vm::587::vm.Vm::(_getCpuStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::CPU stats not available: 'NoneType' object has no attribute '__getitem__' >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,307::vm::623::vm.Vm::(_getNetworkStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Network stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,307::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,308::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,308::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,308::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,310::vm::587::vm.Vm::(_getCpuStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::CPU stats not available: 'NoneType' object has no attribute '__getitem__' >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,310::vm::623::vm.Vm::(_getNetworkStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Network stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,310::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,310::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,310::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:33,310::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >libvirtEventLoop::DEBUG::2014-06-05 09:25:33,594::clientIF::555::vm.Vm::(dispatchLibvirtEvents) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::graphics event phase 1 localAddr {'node': '192.168.11.42', 'service': '', 'family': 0} remoteAddr {'node': '192.168.10.181', 'service': '', 'family': 0}authScheme spice subject [] >libvirtEventLoop::DEBUG::2014-06-05 09:25:33,733::clientIF::555::vm.Vm::(dispatchLibvirtEvents) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::graphics event phase 0 localAddr {'node': '192.168.11.42', 'service': '', 'family': 0} remoteAddr {'node': '192.168.10.181', 'service': '', 'family': 0}authScheme subject [] >libvirtEventLoop::DEBUG::2014-06-05 09:25:33,733::clientIF::555::vm.Vm::(dispatchLibvirtEvents) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::graphics event phase 0 localAddr {'node': '192.168.11.42', 'service': '', 'family': 0} remoteAddr {'node': '192.168.10.181', 'service': '', 'family': 0}authScheme subject [] >libvirtEventLoop::DEBUG::2014-06-05 09:25:33,734::clientIF::555::vm.Vm::(dispatchLibvirtEvents) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::graphics event phase 0 localAddr {'node': '192.168.11.42', 'service': '', 'family': 0} remoteAddr {'node': '192.168.10.181', 'service': '', 'family': 0}authScheme subject [] >libvirtEventLoop::DEBUG::2014-06-05 09:25:33,906::clientIF::555::vm.Vm::(dispatchLibvirtEvents) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::graphics event phase 1 localAddr {'node': '192.168.11.42', 'service': '', 'family': 0} remoteAddr {'node': '192.168.10.181', 'service': '', 'family': 0}authScheme spice subject [] >libvirtEventLoop::DEBUG::2014-06-05 09:25:33,907::clientIF::555::vm.Vm::(dispatchLibvirtEvents) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::graphics event phase 1 localAddr {'node': '192.168.11.42', 'service': '', 'family': 0} remoteAddr {'node': '192.168.10.181', 'service': '', 'family': 0}authScheme spice subject [] >libvirtEventLoop::DEBUG::2014-06-05 09:25:33,911::clientIF::555::vm.Vm::(dispatchLibvirtEvents) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::graphics event phase 1 localAddr {'node': '192.168.11.42', 'service': '', 'family': 0} remoteAddr {'node': '192.168.10.181', 'service': '', 'family': 0}authScheme spice subject [] >Thread-20::DEBUG::2014-06-05 09:25:38,124::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-20::DEBUG::2014-06-05 09:25:38,132::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.00024035 s, 2.3 MB/s\n'; <rc> = 0 >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:38,313::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:38,313::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:38,313::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:38,313::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:38,315::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:38,315::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:38,315::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:38,315::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >Thread-63529::DEBUG::2014-06-05 09:25:39,759::task::595::TaskManager.Task::(_updateState) Task=`442197c4-4efc-4bee-bb98-18aab59f9cf6`::moving from state init -> state preparing >Thread-63529::INFO::2014-06-05 09:25:39,759::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) >Thread-63529::INFO::2014-06-05 09:25:39,759::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-8215-e15f55f66906': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000216338', 'lastCheck': '8.9', 'valid': True}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.00024035', 'lastCheck': '1.6', 'valid': True}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000283246', 'lastCheck': '7.2', 'valid': True}, '63041fa9-e093-4b44-b36f-f39f16d3974f': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000282369', 'lastCheck': '8.7', 'valid': True}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000206051', 'lastCheck': '8.7', 'valid': True}} >Thread-63529::DEBUG::2014-06-05 09:25:39,760::task::1185::TaskManager.Task::(prepare) Task=`442197c4-4efc-4bee-bb98-18aab59f9cf6`::finished: {'2c51d320-88ce-4f23-8215-e15f55f66906': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000216338', 'lastCheck': '8.9', 'valid': True}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.00024035', 'lastCheck': '1.6', 'valid': True}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000283246', 'lastCheck': '7.2', 'valid': True}, '63041fa9-e093-4b44-b36f-f39f16d3974f': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000282369', 'lastCheck': '8.7', 'valid': True}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000206051', 'lastCheck': '8.7', 'valid': True}} >Thread-63529::DEBUG::2014-06-05 09:25:39,760::task::595::TaskManager.Task::(_updateState) Task=`442197c4-4efc-4bee-bb98-18aab59f9cf6`::moving from state preparing -> state finished >Thread-63529::DEBUG::2014-06-05 09:25:39,760::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-63529::DEBUG::2014-06-05 09:25:39,760::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-63529::DEBUG::2014-06-05 09:25:39,760::task::990::TaskManager.Task::(_decref) Task=`442197c4-4efc-4bee-bb98-18aab59f9cf6`::ref 0 aborting False >Thread-63529::DEBUG::2014-06-05 09:25:39,799::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >Thread-63529::DEBUG::2014-06-05 09:25:39,799::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >Thread-63529::DEBUG::2014-06-05 09:25:39,799::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >Thread-63529::DEBUG::2014-06-05 09:25:39,799::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >Thread-19::DEBUG::2014-06-05 09:25:40,864::domainMonitor::192::Storage.DomainMonitorThread::(_monitorDomain) Refreshing domain 2c51d320-88ce-4f23-8215-e15f55f66906 >Thread-19::DEBUG::2014-06-05 09:25:40,877::fileSD::150::Storage.StorageDomain::(__init__) Reading domain in path /rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906 >Thread-19::DEBUG::2014-06-05 09:25:40,878::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend >Thread-19::DEBUG::2014-06-05 09:25:40,884::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=colnas03_IB', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=3', 'POOL_DESCRIPTION=Collogia', 'POOL_DOMAINS=272ec473-6041-42ee-bd1a-732789dd18d4:Active,965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545:Active,2c51d320-88ce-4f23-8215-e15f55f66906:Active,63041fa9-e093-4b44-b36f-f39f16d3974f:Active,bff3a2be-fdd9-4e37-b416-fa4ef7fafba2:Active', 'POOL_SPM_ID=4', 'POOL_SPM_LVER=1', 'POOL_UUID=94ed7a19-fade-4bd6-83f2-2cbb2f730b95', 'REMOTE_PATH=10.10.30.253:/var/nas3/OVirtIB', 'ROLE=Master', 'SDUUID=2c51d320-88ce-4f23-8215-e15f55f66906', 'TYPE=NFS', 'VERSION=3', '_SHA_CKSUM=97f4583421c0b9df2159556471857e406bb3a50c'] >Thread-19::DEBUG::2014-06-05 09:25:40,886::fileSD::609::Storage.StorageDomain::(imageGarbageCollector) Removing remnants of deleted images [] >Thread-19::INFO::2014-06-05 09:25:40,886::sd::383::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 2c51d320-88ce-4f23-8215-e15f55f66906_imageNS already registered >Thread-19::INFO::2014-06-05 09:25:40,886::sd::391::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 2c51d320-88ce-4f23-8215-e15f55f66906_volumeNS already registered >Thread-19::DEBUG::2014-06-05 09:25:40,899::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-19::DEBUG::2014-06-05 09:25:40,908::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n644 bytes (644 B) copied, 0.000195794 s, 3.3 MB/s\n'; <rc> = 0 >Thread-27::DEBUG::2014-06-05 09:25:41,041::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-27::DEBUG::2014-06-05 09:25:41,048::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n363 bytes (363 B) copied, 0.000239555 s, 1.5 MB/s\n'; <rc> = 0 >Thread-32::DEBUG::2014-06-05 09:25:41,061::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-32::DEBUG::2014-06-05 09:25:41,069::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n557 bytes (557 B) copied, 0.000214012 s, 2.6 MB/s\n'; <rc> = 0 >Thread-21::DEBUG::2014-06-05 09:25:42,567::fileSD::259::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/metadata bs=4096 count=1' (cwd None) >Thread-21::DEBUG::2014-06-05 09:25:42,575::fileSD::259::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n357 bytes (357 B) copied, 0.000238642 s, 1.5 MB/s\n'; <rc> = 0 >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:43,322::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:43,323::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:43,323::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:43,323::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:43,324::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:43,325::vm::645::vm.Vm::(_getDiskStats) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda stats not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:43,325::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk hdc latency not available >GuestMonitor-colvm36::DEBUG::2014-06-05 09:25:43,325::vm::684::vm.Vm::(_getDiskLatency) vmId=`803870d2-e365-4ab4-bdcc-4c1d25a03944`::Disk vda latency not available
You cannot view the attachment while viewing its details because your browser does not support IFRAMEs.
View the attachment on a separate page
.
View Attachment As Raw
Actions:
View
Attachments on
bug 1104697
:
902192
|
902193
| 902418 |
902559
|
902561
|
907289
|
908784
|
908785