[Users] ovirt 3.2 migrations failing
Jonathan Horne
jhorne at skopos.us
Wed Jan 9 22:52:28 UTC 2013
yep, sure enough:
[root at d0lppn032 ~]# cat /var/log/libvirtd.log|grep CA
2013-01-09 22:45:30.310+0000: 4413: error :
virNetTLSContextCheckCertFile:92 : Cannot read CA certificate
'/etc/pki/CA/cacert.pem': No such file or directory
[root at d0lppn032 ~]# locate cacert.pem
/etc/pki/vdsm/certs/cacert.pem
is there a config file somewhere i can edit and hopefully get this working?
On 1/9/13 4:39 PM, "Jeff Bailey" <bailey at cs.kent.edu> wrote:
>I don't know any details about the dreyou version you're running but
>look in the libvirtd log on the source host and see if there is a
>complaint about a missing CA cert. That problem existed in the 3.2
>alpha but should have been fixed in the nightlies. I don't know whether
>it made it to the version you're running. It could also be something
>totally different :)
>
>---
>Jeff
>
>On 1/9/2013 8:54 AM, Jonathan Horne wrote:
>> from source:
>>
>> [root at d0lppn032 vdsm]# egrep 'Thread-30209|Thread-30210'
>> /var/log/vdsm/vdsm.log
>> Thread-30209::DEBUG::2013-01-09
>> 07:49:08,543::BindingXMLRPC::908::vds::(wrapper) client
>>[10.32.0.21]::call
>> vmMigrate with ({'src': 'd0lppn032.skopos.me', 'dst':
>> 'd0lppn031.skopos.me:54321', 'vmId':
>> 'e00adf83-78d2-4f65-a259-0e01680f57fd', 'method': 'online'},) {} flowID
>> [343d5f4c]
>> Thread-30209::DEBUG::2013-01-09 07:49:08,543::API::435::vds::(migrate)
>> {'src': 'd0lppn032.skopos.me', 'dst': 'd0lppn031.skopos.me:54321',
>>'vmId':
>> 'e00adf83-78d2-4f65-a259-0e01680f57fd', 'method': 'online'}
>> Thread-30210::DEBUG::2013-01-09
>> 07:49:08,544::vm::139::vm.Vm::(_setupVdsConnection)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Destination server is:
>> d0lppn031.skopos.me:54321
>> Thread-30210::DEBUG::2013-01-09
>> 07:49:08,545::vm::141::vm.Vm::(_setupVdsConnection)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Initiating connection with
>> destination
>> Thread-30209::DEBUG::2013-01-09
>> 07:49:08,545::BindingXMLRPC::915::vds::(wrapper) return vmMigrate with
>> {'status': {'message': 'Migration process starting', 'code': 0}}
>> Thread-30210::DEBUG::2013-01-09
>> 07:49:08,614::libvirtvm::298::vm.Vm::(_getDiskLatency)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Disk vda latency not
>>available
>> Thread-30210::DEBUG::2013-01-09
>> 07:49:08,659::vm::190::vm.Vm::(_prepareGuest)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::migration Process begins
>> Thread-30210::DEBUG::2013-01-09 07:49:08,751::vm::261::vm.Vm::(run)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::migration semaphore
>>acquired
>> Thread-30210::DEBUG::2013-01-09
>> 07:49:09,168::libvirtvm::469::vm.Vm::(_startUnderlyingMigration)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::starting migration to
>> qemu+tls://d0lppn031.skopos.me/system
>> Thread-30210::DEBUG::2013-01-09
>> 07:49:09,230::libvirtvm::370::vm.Vm::(cancel)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::canceling migration
>>downtime
>> thread
>> Thread-30210::DEBUG::2013-01-09
>> 07:49:09,231::libvirtvm::429::vm.Vm::(stop)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::stopping migration monitor
>> thread
>> Thread-30210::ERROR::2013-01-09 07:49:09,232::vm::196::vm.Vm::(_recover)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::operation failed: Failed to
>> connect to remote libvirt URI qemu+tls://d0lppn031.skopos.me/system
>> Thread-30210::ERROR::2013-01-09 07:49:09,374::vm::284::vm.Vm::(run)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Failed to migrate
>>
>>
>>
>> and from destination:
>>
>> [root at d0lppn031 vdsm]# egrep 'Thread-40128|Thread-40129'
>> /var/log/vdsm/vdsm.log
>> Thread-40128::DEBUG::2013-01-09
>> 07:49:08,943::BindingXMLRPC::908::vds::(wrapper) client
>>[10.32.0.32]::call
>> vmMigrationCreate with ({'username': 'root', 'acpiEnable': 'true',
>> 'emulatedMachine': 'pc', 'afterMigrationStatus': 'Up', 'vmId':
>> 'e00adf83-78d2-4f65-a259-0e01680f57fd', 'transparentHugePages': 'true',
>> 'displaySecurePort': '5901', 'timeOffset': 1, 'cpuType': 'SandyBridge',
>> 'custom': {}, 'migrationDest': 'libvirt', 'smp': '4', 'vmType': 'kvm',
>> 'spiceSslCipherSuite': 'DEFAULT', '_srcDomXML': "<domain type='kvm'
>> id='2'>\n <name>d0lpvf051</name>\n
>> <uuid>e00adf83-78d2-4f65-a259-0e01680f57fd</uuid>\n <memory
>> unit='KiB'>4194304</memory>\n <currentMemory
>> unit='KiB'>4194304</currentMemory>\n <vcpu
>>placement='static'>4</vcpu>\n
>> <cputune>\n <shares>1020</shares>\n </cputune>\n <sysinfo
>> type='smbios'>\n <system>\n <entry
>> name='manufacturer'>oVirt</entry>\n <entry name='product'>oVirt
>> Node</entry>\n <entry name='version'>6-3.el6.centos.9</entry>\n
>> <entry name='serial'>4C4C4544-004D-4E10-8036-B3C04F575731</entry>\n
>> <entry name='uuid'>e00adf83-78d2-4f65-a259-0e01680f57fd</entry>\n
>> </system>\n </sysinfo>\n <os>\n <type arch='x86_64'
>> machine='rhel6.3.0'>hvm</type>\n <boot dev='hd'/>\n <smbios
>> mode='sysinfo'/>\n </os>\n <features>\n <acpi/>\n </features>\n
>> <cpu mode='custom' match='exact'>\n <model
>> fallback='allow'>SandyBridge</model>\n <topology sockets='4'
>>cores='1'
>> threads='1'/>\n </cpu>\n <clock offset='variable' adjustment='1'>\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/libexec/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='block' device='disk' snapshot='no'>\n
>> <driver name='qemu' type='qcow2' cache='none' error_policy='stop'
>> io='native'/>\n <source
>>
>>dev='/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5
>>-4
>>
>>9a3-b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a3
>>2-
>> 21d8-498c-b12a-efb43a2ef881'/>\n <target dev='vda' bus='virtio'/>\n
>> <serial>0a9e06f9-2e85-4410-930d-7e381128c212</serial>\n <alias
>> name='virtio-disk0'/>\n <address type='pci' domain='0x0000'
>> bus='0x00' slot='0x06' function='0x0'/>\n </disk>\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='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 <interface type='bridge'>\n
>> <mac address='00:1a:4a:20:00:9e'/>\n <source bridge='ovirtmgmt'/>\n
>> <target dev='vnet0'/>\n <model type='virtio'/>\n
>><filterref
>> filter='vdsm-no-mac-spoofing'/>\n <alias name='net0'/>\n
>> <address type='pci' domain='0x0000' bus='0x00' slot='0x03'
>> function='0x0'/>\n </interface>\n <interface type='bridge'>\n
>> <mac address='00:1a:4a:20:00:9f'/>\n <source bridge='ovirtmgmt'/>\n
>> <target dev='vnet1'/>\n <model type='virtio'/>\n
>><filterref
>> filter='vdsm-no-mac-spoofing'/>\n <alias name='net1'/>\n
>> <address type='pci' domain='0x0000' bus='0x00' slot='0x04'
>> function='0x0'/>\n </interface>\n <console type='pty'
>> tty='/dev/pts/1'>\n <source path='/dev/pts/1'/>\n <target
>> type='virtio' port='0'/>\n <alias name='console0'/>\n
>></console>\n
>> <channel type='unix'>\n <source mode='bind'
>>
>>path='/var/lib/libvirt/qemu/channels/d0lpvf051.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/d0lpvf051.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' port='5900' tlsPort='5901' autoport='yes'
>> listen='0' keymap='en-us' passwdValidTo='2013-01-09T00:22:14'
>> connected='keep'>\n <listen type='address' address='0'/>\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 <video>\n <model type='qxl'
>> vram='65536' 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='none'/>\n</domain>\n", 'memSize': 4096, 'elapsedTimeOffset':
>> 48875.878304004669, 'vmName': 'd0lpvf051', 'nice': '0', 'status': 'Up',
>> 'clientIp': '', 'displayIp': '0', 'displayPort': '5900',
>> 'smpCoresPerSocket': '1', 'smartcardEnable': 'false', 'guestIPs':
>> '10.32.0.51', 'nicModel': 'rtl8139,pv', 'keyboardLayout': 'en-us',
>> 'kvmEnable': 'true', 'pitReinjection': 'false', 'devices':
>>[{'specParams':
>> {'vram': '65536'}, 'alias': 'video0', 'deviceId':
>> '99c46e79-710c-4f60-87eb-904fa496f0a7', 'address': {'slot': '0x02',
>>'bus':
>> '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device':
>> 'qxl', 'type': 'video'}, {'nicModel': 'pv', 'macAddr':
>> '00:1a:4a:20:00:9e', 'network': 'ovirtmgmt', 'alias': 'net0', 'filter':
>> 'vdsm-no-mac-spoofing', 'specParams': {}, 'deviceId':
>> '054f3e29-d531-438b-8d1c-09cbed863bea', 'address': {'slot': '0x03',
>>'bus':
>> '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device':
>> 'bridge', 'type': 'interface', 'name': 'vnet0'}, {'nicModel': 'pv',
>> 'macAddr': '00:1a:4a:20:00:9f', 'network': 'ovirtmgmt', 'alias': 'net1',
>> 'filter': 'vdsm-no-mac-spoofing', 'specParams': {}, 'deviceId':
>> '48ff9261-fbd8-4f0f-a823-4c6451226b95', 'address': {'slot': '0x04',
>>'bus':
>> '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device':
>> 'bridge', 'type': 'interface', 'name': 'vnet1'}, {'target': 4194304,
>> 'specParams': {'model': 'virtio'}, 'alias': 'balloon0', 'deviceId':
>> 'df32c652-f9c6-42db-ae88-579ee90aa714', 'address': {'slot': '0x07',
>>'bus':
>> '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device':
>> 'memballoon', 'type': 'balloon'}, {'index': '2', 'iface': 'ide', 'name':
>> 'hdc', 'alias': 'ide0-1-0', 'shared': 'false', 'specParams': {'path':
>>''},
>> 'readonly': 'True', 'deviceId': '62d5042c-3b75-4cb3-b175-373f66c7356b',
>> 'address': {'bus': '1', 'controller': '0', 'type': 'drive', 'target':
>>'0',
>> 'unit': '0'}, 'device': 'cdrom', 'path': '', 'type': 'disk'},
>>{'address':
>> {'slot': '0x06', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci',
>> 'function': '0x0'}, 'index': 0, 'iface': 'virtio', 'apparentsize':
>> '4294967296', 'alias': 'virtio-disk0', 'imageID':
>> '0a9e06f9-2e85-4410-930d-7e381128c212', 'readonly': 'False', 'shared':
>> 'false', 'truesize': '4294967296', 'type': 'disk', 'domainID':
>> 'd668d949-42f5-49a3-b33f-0b174ac226c5', 'reqsize': '0', 'format': 'cow',
>> 'deviceId': '0a9e06f9-2e85-4410-930d-7e381128c212', 'poolID':
>> 'fdab6642-8928-43d5-8ca1-b68792d70729', 'device': 'disk', 'path':
>>
>>'/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a
>>3-
>>
>>b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21
>>d8
>> -498c-b12a-efb43a2ef881', 'propagateErrors': 'off', 'optional': 'false',
>> 'name': 'vda', 'volumeID': '93410a32-21d8-498c-b12a-efb43a2ef881',
>> 'specParams': {}, 'volumeChain': [{'path':
>>
>>'/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a
>>3-
>>
>>b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21
>>d8
>> -498c-b12a-efb43a2ef881', 'domainID':
>> 'd668d949-42f5-49a3-b33f-0b174ac226c5', 'volumeID':
>> '93410a32-21d8-498c-b12a-efb43a2ef881', 'imageID':
>> '0a9e06f9-2e85-4410-930d-7e381128c212'}]}, {'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'}}, {'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'}}], 'spiceSecureChannels':
>> 'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard',
>> 'display': 'qxl'},) {}
>> Thread-40128::DEBUG::2013-01-09
>> 07:49:08,943::API::470::vds::(migrationCreate) Migration create
>> Thread-40128::INFO::2013-01-09
>> 07:49:08,944::API::607::vds::(_getNetworkIp) network None: using 0
>> Thread-40128::INFO::2013-01-09
>> 07:49:08,944::clientIF::334::vds::(createVm) vmContainerLock acquired by
>> vm e00adf83-78d2-4f65-a259-0e01680f57fd
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,952::vm::651::vm.Vm::(_startUnderlyingVm)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Start
>> Thread-40128::DEBUG::2013-01-09
>> 07:49:08,953::clientIF::348::vds::(createVm) Total desktops after
>>creation
>> of e00adf83-78d2-4f65-a259-0e01680f57fd is 1
>> Thread-40128::DEBUG::2013-01-09
>>
>>07:49:08,954::libvirtvm::2921::vm.Vm::(waitForMigrationDestinationPrepare
>>)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::migration destination:
>> waiting for VM creation
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,954::vm::655::vm.Vm::(_startUnderlyingVm)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::_ongoingCreations acquired
>> Thread-40129::INFO::2013-01-09
>> 07:49:08,955::libvirtvm::1430::vm.Vm::(_run)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::VM wrapper has started
>> Thread-40128::DEBUG::2013-01-09
>>
>>07:49:08,955::libvirtvm::2927::vm.Vm::(waitForMigrationDestinationPrepare
>>)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::migration destination:
>> waiting 36s for path preparation
>> Thread-40129::WARNING::2013-01-09
>> 07:49:08,955::vm::455::vm.Vm::(getConfDevices)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Unknown type found, device:
>> '{'device': 'unix', 'alias': 'channel0', 'type': 'channel', 'address':
>> {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '1'}}'
>> found
>> Thread-40129::WARNING::2013-01-09
>> 07:49:08,956::vm::455::vm.Vm::(getConfDevices)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Unknown type found, device:
>> '{'device': 'unix', 'alias': 'channel1', 'type': 'channel', 'address':
>> {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '2'}}'
>> found
>> Thread-40129::WARNING::2013-01-09
>> 07:49:08,957::vm::455::vm.Vm::(getConfDevices)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Unknown type found, device:
>> '{'device': 'spicevmc', 'alias': 'channel2', 'type': 'channel',
>>'address':
>> {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '3'}}'
>> found
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,958::task::568::TaskManager.Task::(_updateState)
>> Task=`fce2eb32-aa53-4742-962d-11a07cc9f06d`::moving from state init ->
>> state preparing
>> Thread-40129::INFO::2013-01-09
>> 07:49:08,958::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='d668d949-42f5-49a3-b33f-0b174ac226c5',
>> spUUID='fdab6642-8928-43d5-8ca1-b68792d70729',
>> imgUUID='0a9e06f9-2e85-4410-930d-7e381128c212',
>> volUUID='93410a32-21d8-498c-b12a-efb43a2ef881', options=None)
>> Thread-40129::INFO::2013-01-09
>> 07:49:08,959::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '5368709120',
>>'apparentsize':
>> '5368709120'}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,959::task::1151::TaskManager.Task::(prepare)
>> Task=`fce2eb32-aa53-4742-962d-11a07cc9f06d`::finished: {'truesize':
>> '5368709120', 'apparentsize': '5368709120'}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,959::task::568::TaskManager.Task::(_updateState)
>> Task=`fce2eb32-aa53-4742-962d-11a07cc9f06d`::moving from state preparing
>> -> state finished
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,960::resourceManager::830::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources {}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,960::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,960::task::957::TaskManager.Task::(_decref)
>> Task=`fce2eb32-aa53-4742-962d-11a07cc9f06d`::ref 0 aborting False
>> Thread-40129::INFO::2013-01-09
>> 07:49:08,961::clientIF::316::vds::(prepareVolumePath) prepared volume
>> path:
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,961::task::568::TaskManager.Task::(_updateState)
>> Task=`d6ca414a-5a97-47a2-a2ec-ea3acd992aca`::moving from state init ->
>> state preparing
>> Thread-40129::INFO::2013-01-09
>> 07:49:08,961::logUtils::41::dispatcher::(wrapper) Run and protect:
>> prepareImage(sdUUID='d668d949-42f5-49a3-b33f-0b174ac226c5',
>> spUUID='fdab6642-8928-43d5-8ca1-b68792d70729',
>> imgUUID='0a9e06f9-2e85-4410-930d-7e381128c212',
>> volUUID='93410a32-21d8-498c-b12a-efb43a2ef881')
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,962::resourceManager::190::ResourceManager.Request::(__init__)
>>
>>ResName=`Storage.d668d949-42f5-49a3-b33f-0b174ac226c5`ReqID=`4261e498-e72
>>0-
>> 42fd-8e48-ab390bd84a29`::Request was made in
>> '/usr/share/vdsm/storage/resourceManager.py' line '189' at '__init__'
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,962::resourceManager::504::ResourceManager::(registerResource)
>> Trying to register resource
>>'Storage.d668d949-42f5-49a3-b33f-0b174ac226c5'
>> for lock type 'shared'
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,963::resourceManager::547::ResourceManager::(registerResource)
>> Resource 'Storage.d668d949-42f5-49a3-b33f-0b174ac226c5' is free. Now
>> locking as 'shared' (1 active user)
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,963::resourceManager::227::ResourceManager.Request::(grant)
>>
>>ResName=`Storage.d668d949-42f5-49a3-b33f-0b174ac226c5`ReqID=`4261e498-e72
>>0-
>> 42fd-8e48-ab390bd84a29`::Granted request
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,964::task::794::TaskManager.Task::(resourceAcquired)
>> Task=`d6ca414a-5a97-47a2-a2ec-ea3acd992aca`::_resourcesAcquired:
>> Storage.d668d949-42f5-49a3-b33f-0b174ac226c5 (shared)
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,964::task::957::TaskManager.Task::(_decref)
>> Task=`d6ca414a-5a97-47a2-a2ec-ea3acd992aca`::ref 1 aborting False
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,965::lvm::409::OperationMutex::(_reloadlvs) Operation 'lvm
>>reload
>> operation' got the operation mutex
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:08,965::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo
>>-n
>> /sbin/lvm lvs --config " devices { preferred_names =
>>[\\"^/dev/mapper/\\"]
>> ignore_suspended_devices=1 write_cache_state=0
>>disable_after_error_count=3
>> filter = [ \\"a%36090a028108c8e5dca0e950a0000e01a%\\", \\"r%.*%\\" ] }
>> global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 }
>> backup { retain_min = 50 retain_days = 0 } " --noheadings --units b
>> --nosuffix --separator | -o
>> uuid,name,vg_name,attr,size,seg_start_pe,devices,tags
>> d668d949-42f5-49a3-b33f-0b174ac226c5' (cwd None)
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,081::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
>> ''; <rc> = 0
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,094::lvm::442::OperationMutex::(_reloadlvs) Operation 'lvm
>>reload
>> operation' released the operation mutex
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,106::misc::84::Storage.Misc.excCmd::(<lambda>) '/bin/dd
>> iflag=direct skip=4 bs=512
>> if=/dev/d668d949-42f5-49a3-b33f-0b174ac226c5/metadata count=1' (cwd
>>None)
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,125::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
>> '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.00859049
>>s,
>> 59.6 kB/s\n'; <rc> = 0
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,126::misc::325::Storage.Misc::(validateDDBytes) err: ['1+0
>> records in', '1+0 records out', '512 bytes (512 B) copied, 0.00859049 s,
>> 59.6 kB/s'], size: 512
>> Thread-40129::INFO::2013-01-09
>> 07:49:09,126::image::344::Storage.Image::(getChain)
>> sdUUID=d668d949-42f5-49a3-b33f-0b174ac226c5
>> imgUUID=0a9e06f9-2e85-4410-930d-7e381128c212
>> chain=[<storage.blockVolume.BlockVolume object at 0x7f5760041490>]
>> Thread-40129::INFO::2013-01-09
>> 07:49:09,127::logUtils::44::dispatcher::(wrapper) Run and protect:
>> prepareImage, Return response: {'path':
>>
>>'/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a
>>3-
>>
>>b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21
>>d8
>> -498c-b12a-efb43a2ef881', 'chain': [{'path':
>>
>>'/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a
>>3-
>>
>>b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21
>>d8
>> -498c-b12a-efb43a2ef881', 'domainID':
>> 'd668d949-42f5-49a3-b33f-0b174ac226c5', 'volumeID':
>> '93410a32-21d8-498c-b12a-efb43a2ef881', 'imageID':
>> '0a9e06f9-2e85-4410-930d-7e381128c212'}]}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,128::task::1151::TaskManager.Task::(prepare)
>> Task=`d6ca414a-5a97-47a2-a2ec-ea3acd992aca`::finished: {'path':
>>
>>'/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a
>>3-
>>
>>b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21
>>d8
>> -498c-b12a-efb43a2ef881', 'chain': [{'path':
>>
>>'/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a
>>3-
>>
>>b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21
>>d8
>> -498c-b12a-efb43a2ef881', 'domainID':
>> 'd668d949-42f5-49a3-b33f-0b174ac226c5', 'volumeID':
>> '93410a32-21d8-498c-b12a-efb43a2ef881', 'imageID':
>> '0a9e06f9-2e85-4410-930d-7e381128c212'}]}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,128::task::568::TaskManager.Task::(_updateState)
>> Task=`d6ca414a-5a97-47a2-a2ec-ea3acd992aca`::moving from state preparing
>> -> state finished
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,128::resourceManager::830::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources
>> {'Storage.d668d949-42f5-49a3-b33f-0b174ac226c5': < ResourceRef
>> 'Storage.d668d949-42f5-49a3-b33f-0b174ac226c5', isValid: 'True' obj:
>> 'None'>}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,129::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,129::resourceManager::557::ResourceManager::(releaseResource)
>> Trying to release resource
>>'Storage.d668d949-42f5-49a3-b33f-0b174ac226c5'
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,130::resourceManager::573::ResourceManager::(releaseResource)
>> Released resource 'Storage.d668d949-42f5-49a3-b33f-0b174ac226c5' (0
>>active
>> users)
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,130::resourceManager::578::ResourceManager::(releaseResource)
>> Resource 'Storage.d668d949-42f5-49a3-b33f-0b174ac226c5' is free, finding
>> out if anyone is waiting for it.
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,131::resourceManager::585::ResourceManager::(releaseResource)
>>No
>> one is waiting for resource
>> 'Storage.d668d949-42f5-49a3-b33f-0b174ac226c5', Clearing records.
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,131::task::957::TaskManager.Task::(_decref)
>> Task=`d6ca414a-5a97-47a2-a2ec-ea3acd992aca`::ref 0 aborting False
>> Thread-40129::INFO::2013-01-09
>> 07:49:09,131::clientIF::316::vds::(prepareVolumePath) prepared volume
>> path:
>>
>>/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a3
>>-b
>>
>>33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21d
>>8-
>> 498c-b12a-efb43a2ef881
>> Thread-40128::DEBUG::2013-01-09
>> 07:49:09,145::API::483::vds::(migrationCreate) Destination VM creation
>> succeeded
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,144::vm::672::vm.Vm::(_startUnderlyingVm)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::_ongoingCreations released
>> Thread-40128::DEBUG::2013-01-09
>> 07:49:09,147::BindingXMLRPC::915::vds::(wrapper) return
>>vmMigrationCreate
>> with {'status': {'message': 'Done', 'code': 0}, 'migrationPort': 0,
>> 'params': {'status': 'Migration Destination', 'acpiEnable': 'true',
>> 'emulatedMachine': 'pc', 'afterMigrationStatus': 'Up',
>> 'spiceSecureChannels':
>> 'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard',
>> 'pid': '0', 'transparentHugePages': 'true', 'displaySecurePort': '-1',
>> 'timeOffset': 1, 'cpuType': 'SandyBridge', 'smp': '4', 'migrationDest':
>> 'libvirt', 'custom': {}, 'vmType': 'kvm', 'spiceSslCipherSuite':
>> 'DEFAULT', 'memSize': 4096, 'vmName': 'd0lpvf051', 'nice': '0',
>> 'username': 'root', 'vmId': 'e00adf83-78d2-4f65-a259-0e01680f57fd',
>> 'displayIp': '0', 'keyboardLayout': 'en-us', 'displayPort': '-1',
>> 'smartcardEnable': 'false', 'guestIPs': '10.32.0.51', 'nicModel':
>> 'rtl8139,pv', 'smpCoresPerSocket': '1', 'kvmEnable': 'true',
>> 'pitReinjection': 'false', 'devices': [{'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': '65536'}, 'alias':
>> 'video0', 'deviceId': '99c46e79-710c-4f60-87eb-904fa496f0a7', 'address':
>> {'slot': '0x02', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci',
>> 'function': '0x0'}, 'device': 'qxl', 'type': 'video'}, {'nicModel':
>>'pv',
>> 'macAddr': '00:1a:4a:20:00:9e', 'network': 'ovirtmgmt', 'alias': 'net0',
>> 'filter': 'vdsm-no-mac-spoofing', 'specParams': {}, 'deviceId':
>> '054f3e29-d531-438b-8d1c-09cbed863bea', 'address': {'slot': '0x03',
>>'bus':
>> '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device':
>> 'bridge', 'type': 'interface', 'name': 'vnet0'}, {'nicModel': 'pv',
>> 'macAddr': '00:1a:4a:20:00:9f', 'network': 'ovirtmgmt', 'alias': 'net1',
>> 'filter': 'vdsm-no-mac-spoofing', 'specParams': {}, 'deviceId':
>> '48ff9261-fbd8-4f0f-a823-4c6451226b95', 'address': {'slot': '0x04',
>>'bus':
>> '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device':
>> 'bridge', 'type': 'interface', 'name': 'vnet1'}, {'target': 4194304,
>> 'specParams': {'model': 'virtio'}, 'alias': 'balloon0', 'deviceId':
>> 'df32c652-f9c6-42db-ae88-579ee90aa714', 'address': {'slot': '0x07',
>>'bus':
>> '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device':
>> 'memballoon', 'type': 'balloon'}, {'index': '2', 'iface': 'ide', 'name':
>> 'hdc', 'alias': 'ide0-1-0', 'shared': 'false', 'specParams': {'path':
>>''},
>> 'readonly': 'True', 'deviceId': '62d5042c-3b75-4cb3-b175-373f66c7356b',
>> 'address': {'bus': '1', 'controller': '0', 'type': 'drive', 'target':
>>'0',
>> 'unit': '0'}, 'device': 'cdrom', 'path': '', 'type': 'disk'},
>>{'address':
>> {'slot': '0x06', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci',
>> 'function': '0x0'}, 'index': 0, 'iface': 'virtio', 'apparentsize':
>> '5368709120', 'alias': 'virtio-disk0', 'imageID':
>> '0a9e06f9-2e85-4410-930d-7e381128c212', 'readonly': 'False', 'shared':
>> 'false', 'truesize': '5368709120', 'type': 'disk', 'domainID':
>> 'd668d949-42f5-49a3-b33f-0b174ac226c5', 'reqsize': '0', 'format': 'cow',
>> 'deviceId': '0a9e06f9-2e85-4410-930d-7e381128c212', 'poolID':
>> 'fdab6642-8928-43d5-8ca1-b68792d70729', 'device': 'disk', 'path':
>>
>>'/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a
>>3-
>>
>>b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21
>>d8
>> -498c-b12a-efb43a2ef881', 'propagateErrors': 'off', 'optional': 'false',
>> 'name': 'vda', 'volumeID': '93410a32-21d8-498c-b12a-efb43a2ef881',
>> 'specParams': {}, 'volumeChain': [{'path':
>>
>>'/rhev/data-center/fdab6642-8928-43d5-8ca1-b68792d70729/d668d949-42f5-49a
>>3-
>>
>>b33f-0b174ac226c5/images/0a9e06f9-2e85-4410-930d-7e381128c212/93410a32-21
>>d8
>> -498c-b12a-efb43a2ef881', 'domainID':
>> 'd668d949-42f5-49a3-b33f-0b174ac226c5', 'volumeID':
>> '93410a32-21d8-498c-b12a-efb43a2ef881', 'imageID':
>> '0a9e06f9-2e85-4410-930d-7e381128c212'}]}, {'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'}}], 'clientIp': '', 'display':
>>'qxl'}}
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,148::libvirtvm::1751::vm.Vm::(_waitForIncomingMigrationFinish)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Waiting 300 seconds for end
>> of migration
>> Thread-40129::ERROR::2013-01-09
>> 07:49:09,310::vm::696::vm.Vm::(_startUnderlyingVm)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::The vm start process failed
>> Thread-40129::DEBUG::2013-01-09
>> 07:49:09,311::vm::1045::vm.Vm::(setDownStatus)
>> vmId=`e00adf83-78d2-4f65-a259-0e01680f57fd`::Changed state to Down:
>>Domain
>> not found: no domain with matching uuid
>> 'e00adf83-78d2-4f65-a259-0e01680f57fd'
>>
>>
>>
>> thank you for your help!
>> jonathan
>>
>>
>>
>>
>> On 1/9/13 1:18 AM, "Haim Ateya" <hateya at redhat.com> wrote:
>>
>>>
>>> ----- Original Message -----
>>>> From: "Jonathan Horne" <jhorne at skopos.us>
>>>> To: "Jonathan Horne" <jhorne at skopos.us>, users at ovirt.org
>>>> Sent: Tuesday, January 8, 2013 10:26:52 PM
>>>> Subject: Re: [Users] ovirt 3.2 migrations failing
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> so far i see this, and it looks related:
>>> this only means libvirt can't find the guest on the host, was it on
>>> source or destination?
>>>
>>> please run the following:
>>>
>>> on source server:
>>>
>>> - egrep 'vmMigrate|_setupVdsConnection' /var/log/vdsm/vdsm.log
>>> - then, from output, get the Thread number of both commands and run
>>>grep
>>> again:
>>> - egrep 'Thread-$x|Thread-$y' /var/log/vdsm/vdsm.log
>>>
>>> on destination server:
>>>
>>> - egrep 'vmMigrationCreate|prepareImage' /var/log/vdsm/vdsm.log
>>> - then, from output, get the Thread number of both commands and run
>>>grep
>>> again:
>>> - egrep 'Thread-$x|Thread-$y' /var/log/vdsm/vdsm.log
>>>
>>> please paste it here.
>>>
>>> Haim
>>>
>>>
>>>
>>>
>>>>
>>>>
>>>> Traceback (most recent call last):
>>>> File "/usr/share/vdsm/vm.py", line 676, in _startUnderlyingVm
>>>> self._waitForIncomingMigrationFinish()
>>>> File "/usr/share/vdsm/libvirtvm.py", line 1757, in
>>>> _waitForIncomingMigrationFinish
>>>> self._connection.lookupByUUIDString(self.id),
>>>> File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py",
>>>> line 111, in wrapper
>>>> ret = f(*args, **kwargs)
>>>> File "/usr/lib64/python2.6/site-packages/libvirt.py", line 2682, in
>>>> lookupByUUIDString
>>>> if ret is None:raise libvirtError('virDomainLookupByUUIDString()
>>>> failed', conn=self)
>>>> libvirtError: Domain not found: no domain with matching uuid
>>>> '063c7cbe-c569-4df3-b9a7-6474c41d797e'
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> From: Jonathan Horne < jhorne at skopos.us >
>>>> Date: Tuesday, January 8, 2013 2:15 PM
>>>> To: " users at ovirt.org " < users at ovirt.org >
>>>> Subject: [Users] ovirt 3.2 migrations failing
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> i just built up 2 nodes and a manager on 3.2 dreyou packages, and now
>>>> that i have a VM up and installed with rhev agent, the VM is unable
>>>> to migrate. the failure is pretty much immediate.
>>>>
>>>>
>>>> i don't know where to begin troubleshooting this, can someone help me
>>>> get going in the right direction? just let me know what logs are
>>>> appropriate and i will post them up.
>>>>
>>>>
>>>> thanks,
>>>> jonathan
>>>>
>>>>
>>>>
>>>> This is a PRIVATE message. If you are not the intended recipient,
>>>> please delete without copying and kindly advise us by e-mail of the
>>>> mistake in delivery. NOTE: Regardless of content, this e-mail shall
>>>> not operate to bind SKOPOS to any order or other contract unless
>>>> pursuant to explicit written agreement or government initiative
>>>> expressly permitting the use of e-mail for such purpose.
>>>>
>>>> This is a PRIVATE message. If you are not the intended recipient,
>>>> please delete without copying and kindly advise us by e-mail of the
>>>> mistake in delivery. NOTE: Regardless of content, this e-mail shall
>>>> not operate to bind SKOPOS to any order or other contract unless
>>>> pursuant to explicit written agreement or government initiative
>>>> expressly permitting the use of e-mail for such purpose.
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users at ovirt.org
>>>> http://lists.ovirt.org/mailman/listinfo/users
>>>>
>>
>> ________________________________
>> This is a PRIVATE message. If you are not the intended recipient,
>>please delete without copying and kindly advise us by e-mail of the
>>mistake in delivery. NOTE: Regardless of content, this e-mail shall not
>>operate to bind SKOPOS to any order or other contract unless pursuant to
>>explicit written agreement or government initiative expressly permitting
>>the use of e-mail for such purpose.
>> _______________________________________________
>> Users mailing list
>> Users at ovirt.org
>> http://lists.ovirt.org/mailman/listinfo/users
>
>_______________________________________________
>Users mailing list
>Users at ovirt.org
>http://lists.ovirt.org/mailman/listinfo/users
________________________________
This is a PRIVATE message. If you are not the intended recipient, please delete without copying and kindly advise us by e-mail of the mistake in delivery. NOTE: Regardless of content, this e-mail shall not operate to bind SKOPOS to any order or other contract unless pursuant to explicit written agreement or government initiative expressly permitting the use of e-mail for such purpose.
More information about the Users
mailing list