3:54 p.m.
On 01/03/2013 05:07 PM, Tom Brown wrote:
> interesting, please search for migrationCreate command on desination host and search
for ERROR afterwords, what do you see?
>
> ----- Original Message -----
>> From: "Tom Brown" <tom(a)ng23.net>
>> To: users(a)ovirt.org
>> Sent: Thursday, January 3, 2013 4:12:05 PM
>> Subject: [Users] oVirt 3.1 - VM Migration Issue
>>
>>
>> Hi
>>
>> I seem to have an issue with a single VM and migration, other VM's
>> can migrate OK - When migrating from the GUI it appears to just hang
>> but in the engine.log i see the following
>>
>> 2013-01-03 14:03:10,359 INFO [org.ovirt.engine.core.bll.VdsSelector]
>> (ajp--0.0.0.0-8009-59) Checking for a specific VDS only -
>> id:a2d84a1e-3e18-11e2-8851-3cd92b4c8e89,
>> name:ovirt-node.domain-name, host_name(ip):10.192.42.165
>> 2013-01-03 14:03:10,411 INFO
>> [org.ovirt.engine.core.bll.MigrateVmToServerCommand]
>> (pool-3-thread-48) [4d32917d] Running command:
>> MigrateVmToServerCommand internal: false. Entities affected : ID:
>> 9dc63ce4-0f76-4963-adfe-6f8eb1a44806 Type: VM
>> 2013-01-03 14:03:10,413 INFO [org.ovirt.engine.core.bll.VdsSelector]
>> (pool-3-thread-48) [4d32917d] Checking for a specific VDS only -
>> id:a2d84a1e-3e18-11e2-8851-3cd92b4c8e89,
>> name:ovirt-node.domain-name, host_name(ip):10.192.42.165
>> 2013-01-03 14:03:11,028 INFO
>> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand]
>> (pool-3-thread-48) [4d32917d] START, MigrateVDSCommand(vdsId =
>> 1a52b722-43a1-11e2-af96-3cd92b4c8e89,
>> vmId=9dc63ce4-0f76-4963-adfe-6f8eb1a44806, srcHost=10.192.42.196,
>> dstVdsId=a2d84a1e-3e18-11e2-8851-3cd92b4c8e89,
>> dstHost=10.192.42.165:54321, migrationMethod=ONLINE), log id:
>> 5011789b
>> 2013-01-03 14:03:11,030 INFO
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand]
>> (pool-3-thread-48) [4d32917d] VdsBroker::migrate::Entered
>> (vm_guid=9dc63ce4-0f76-4963-adfe-6f8eb1a44806,
>> srcHost=10.192.42.196, dstHost=10.192.42.165:54321, method=online
>> 2013-01-03 14:03:11,031 INFO
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand]
>> (pool-3-thread-48) [4d32917d] START, MigrateBrokerVDSCommand(vdsId =
>> 1a52b722-43a1-11e2-af96-3cd92b4c8e89,
>> vmId=9dc63ce4-0f76-4963-adfe-6f8eb1a44806, srcHost=10.192.42.196,
>> dstVdsId=a2d84a1e-3e18-11e2-8851-3cd92b4c8e89,
>> dstHost=10.192.42.165:54321, migrationMethod=ONLINE), log id:
>> 7cd53864
>> 2013-01-03 14:03:11,041 INFO
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand]
>> (pool-3-thread-48) [4d32917d] FINISH, MigrateBrokerVDSCommand, log
>> id: 7cd53864
>> 2013-01-03 14:03:11,086 INFO
>> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand]
>> (pool-3-thread-48) [4d32917d] FINISH, MigrateVDSCommand, return:
>> MigratingFrom, log id: 5011789b
>> 2013-01-03 14:03:11,606 INFO
>> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
>> (QuartzScheduler_Worker-29) vds::refreshVmList vm id
>> 9dc63ce4-0f76-4963-adfe-6f8eb1a44806 is migrating to vds
>> ovirt-node.domain-name ignoring it in the refresh till migration is
>> done
>> 2013-01-03 14:03:12,836 INFO
>> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
>> (QuartzScheduler_Worker-36) VM test002.domain-name
>> 9dc63ce4-0f76-4963-adfe-6f8eb1a44806 moved from MigratingFrom --> Up
>> 2013-01-03 14:03:12,837 INFO
>> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
>> (QuartzScheduler_Worker-36) adding VM
>> 9dc63ce4-0f76-4963-adfe-6f8eb1a44806 to re-run list
>> 2013-01-03 14:03:12,852 ERROR
>> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
>> (QuartzScheduler_Worker-36) Rerun vm
>> 9dc63ce4-0f76-4963-adfe-6f8eb1a44806. Called from vds
>> ovirt-node002.domain-name
>> 2013-01-03 14:03:12,855 INFO
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand]
>> (pool-3-thread-48) START, MigrateStatusVDSCommand(vdsId =
>> 1a52b722-43a1-11e2-af96-3cd92b4c8e89,
>> vmId=9dc63ce4-0f76-4963-adfe-6f8eb1a44806), log id: 4721a1f3
>> 2013-01-03 14:03:12,864 ERROR
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
>> (pool-3-thread-48) Failed in MigrateStatusVDS method
>> 2013-01-03 14:03:12,865 ERROR
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
>> (pool-3-thread-48) Error code migrateErr and error message
>> VDSGenericException: VDSErrorException: Failed to MigrateStatusVDS,
>> error = Fatal error during migration
>> 2013-01-03 14:03:12,865 INFO
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
>> (pool-3-thread-48) Command
>> org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand
>> return value
>> Class Name:
>> org.ovirt.engine.core.vdsbroker.vdsbroker.StatusOnlyReturnForXmlRpc
>> mStatus Class Name:
>> org.ovirt.engine.core.vdsbroker.vdsbroker.StatusForXmlRpc
>> mCode 12
>> mMessage Fatal error during migration
>>
>>
>> 2013-01-03 14:03:12,866 INFO
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
>> (pool-3-thread-48) Vds: ovirt-node002.itvonline.ads
>> 2013-01-03 14:03:12,867 ERROR
>> [org.ovirt.engine.core.vdsbroker.VDSCommandBase] (pool-3-thread-48)
>> Command MigrateStatusVDS execution failed. Exception:
>> VDSErrorException: VDSGenericException: VDSErrorException: Failed to
>> MigrateStatusVDS, error = Fatal error during migration
>> 2013-01-03 14:03:12,867 INFO
>> [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand]
>> (pool-3-thread-48) FINISH, MigrateStatusVDSCommand, log id: 4721a1f3
>>
>> Does anyone have any idea what this might be? I am using 3.1 from
>> dreyou as these are CentOS 6 nodes
>>
any clue on which log on the new host ? I see the following in messages
VDSM is the
virtualization agent. look at /var/log/vdsm/vdsm.log
Jan 3 16:03:20 ovirt-node vdsm Storage.LVM WARNING lvm vgs failed: 5 [] [' Volume
group "ab686999-f320-4a61-ae07-e99c2f858996" not found']
Jan 3 16:03:20 ovirt-node vdsm Storage.StorageDomain WARNING Resource namespace
ab686999-f320-4a61-ae07-e99c2f858996_imageNS already registered
Jan 3 16:03:20 ovirt-node vdsm Storage.StorageDomain WARNING Resource namespace
ab686999-f320-4a61-ae07-e99c2f858996_volumeNS already registered
Jan 3 16:03:58 ovirt-node vdsm vm.Vm WARNING
vmId=`9dc63ce4-0f76-4963-adfe-6f8eb1a44806`::Unknown type found, device:
'{'device': 'unix', 'alias': 'channel0',
'type': 'channel', 'address': {'bus': '0',
'controller': '0', 'type': 'virtio-serial',
'port': '1'}}' found
Jan 3 16:03:58 ovirt-node vdsm vm.Vm WARNING
vmId=`9dc63ce4-0f76-4963-adfe-6f8eb1a44806`::Unknown type found, device:
'{'device': 'unix', 'alias': 'channel1',
'type': 'channel', 'address': {'bus': '0',
'controller': '0', 'type': 'virtio-serial',
'port': '2'}}' found
Jan 3 16:03:59 ovirt-node kernel: device vnet2 entered promiscuous mode
Jan 3 16:03:59 ovirt-node kernel: ovirtmgmt: port 4(vnet2) entering forwarding state
Jan 3 16:03:59 ovirt-node kernel: ovirtmgmt: port 4(vnet2) entering disabled state
Jan 3 16:03:59 ovirt-node kernel: device vnet2 left promiscuous mode
Jan 3 16:03:59 ovirt-node kernel: ovirtmgmt: port 4(vnet2) entering disabled state
and the following in the qemu log for that VM on the new node
2013-01-03 16:03:59.706+0000: starting up
LC_ALL=C PATH=/sbin:/usr/sbin:/bin:/usr/bin QEMU_AUDIO_DRV=none /usr/libexec/qemu-kvm -S
-M rhel6.3.0 -cpu Nehalem -enable-kvm -m 1024 -smp 1,sockets=1,cores=1,threads=1 -name
test002.itvonline.ads -uuid 9dc63ce4-0f76-4963-adfe-6f8eb1a44806 -smbios
type=1,manufacturer=oVirt,product=oVirt
Node,version=6-3.el6.centos.9,serial=55414E03-C241-11DF-BBDA-64093408D485_d4:85:64:09:34:08,uuid=9dc63ce4-0f76-4963-adfe-6f8eb1a44806
-nodefconfig -nodefaults -chardev
socket,id=charmonitor,path=/var/lib/libvirt/qemu/test002.itvonline.ads.monitor,server,nowait
-mon chardev=charmonitor,id=monitor,mode=control -rtc
base=2013-01-03T16:03:58,driftfix=slew -no-shutdown -device
virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x4 -device
piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -drive
if=none,media=cdrom,id=drive-ide0-1-0,readonly=on,format=raw,serial= -device
ide-drive,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0,bootindex=1 -drive
file=/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5
dda7/2a1939bd-9fa3-4896-b8a9-46234172aae7/images/e8711e5d-2f06-4c0f-b5c6-fa0806d7448f/0d93c51f-f838-4143-815c-9b3457d1a934,if=none,id=drive-virtio-disk0,format=raw,serial=e8711e5d-2f06-4c0f-b5c6-fa0806d7448f,cache=none,werror=stop,rerror=stop,aio=threads
-device
virtio-blk-pci,scsi=off,bus=pci.0,addr=0x5,drive=drive-virtio-disk0,id=virtio-disk0
-netdev tap,fd=32,id=hostnet0,vhost=on,vhostfd=33 -device
virtio-net-pci,netdev=hostnet0,id=net0,mac=00:1a:4a:c0:2a:00,bus=pci.0,addr=0x3 -chardev
socket,id=charchannel0,path=/var/lib/libvirt/qemu/channels/test002.itvonline.ads.com.redhat.rhevm.vdsm,server,nowait
-device
virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.rhevm.vdsm
-chardev
socket,id=charchannel1,path=/var/lib/libvirt/qemu/channels/test002.itvonline.ads.org.qemu.guest_agent.0,server,nowait
-device
virtserialport,bus=virtio-serial0.0,nr=2,chardev=charchannel1,id=channel1,name=org.qemu.guest_agent.0
-chardev pty,id=charconsole0 -de
vice virtconsole,chardev=charconsole0,id=console0 -device usb-tablet,id=input0 -vnc
10.192.42.165:4,password -k en-us -vga qxl -global qxl-vga.vram_size=67108864 -incoming
tcp:0.0.0.0:49160 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x6
2013-01-03 16:03:59.955+0000: shutting down
but thats about it?
thanks
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
5:18 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
--Apple-Mail=_B91DF312-1386-4884-ADD0-7FF314F05FC2
Content-Transfer-Encoding: 7bit
Content-Type: text/plain;
charset=iso-8859-1
VDSM is the virtualization agent. look at /var/log/vdsm/vdsm.log
many thanks - attached is the snip of that log when i try the migration
thanks
--Apple-Mail=_B91DF312-1386-4884-ADD0-7FF314F05FC2
Content-Disposition: attachment;
filename=migrate.log
Content-Type: application/octet-stream;
x-unix-mode=0644;
name="migrate.log"
Content-Transfer-Encoding: quoted-printable
Thread-2390720::DEBUG::2013-01-07=20=
12:13:11,241::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`325ab4a5-c999-4d9f-8aa8-0d1a4e4124cd`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390720::INFO::2013-01-07=20=
12:13:11,242::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats(options=3DNone)=0AThread-2390720::INFO::2013-01-07=20=
12:13:11,242::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats,=20Return=20response:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00224804878235',=20'lastCheck':=20'4.4',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00211691856384',=20'lastCheck':=20'7.2',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00240302085876',=20'lastCheck':=20'7.0',=20'code':=200,=20'valid':=20=
True}}=0AThread-2390720::DEBUG::2013-01-07=20=
12:13:11,242::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`325ab4a5-c999-4d9f-8aa8-0d1a4e4124cd`::finished:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00224804878235',=20'lastCheck':=20'4.4',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00211691856384',=20'lastCheck':=20'7.2',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00240302085876',=20'lastCheck':=20'7.0',=20'code':=200,=20'valid':=20=
True}}=0AThread-2390720::DEBUG::2013-01-07=20=
12:13:11,242::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`325ab4a5-c999-4d9f-8aa8-0d1a4e4124cd`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390720::DEBUG::2013-01-07=20=
12:13:11,242::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390720::DEBUG::2013-01-07=20=
12:13:11,243::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390720::DEBUG::2013-01-07=20=
12:13:11,243::task::957::TaskManager.Task::(_decref)=20=
Task=3D`325ab4a5-c999-4d9f-8aa8-0d1a4e4124cd`::ref=200=20aborting=20=
False=0AThread-2390721::DEBUG::2013-01-07=20=
12:13:11,256::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`a08884f6-d634-4d1d-a0ef-f77cd96f0953`::Disk=20vda=20latency=20=
not=20available=0AThread-2390722::DEBUG::2013-01-07=20=
12:13:12,808::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2390722::DEBUG::2013-01-07=20=
12:13:12,808::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`054ac6c0-f5df-48ed-8db5-a0678f9d37c3`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390722::INFO::2013-01-07=20=
12:13:12,808::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2390722::INFO::2013-01-07=20=
12:13:12,809::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus,=20Return=20response:=20{'spm_st':=20{'spmId':=201,=20=
'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2390722::DEBUG::2013-01-07=20=
12:13:12,809::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`054ac6c0-f5df-48ed-8db5-a0678f9d37c3`::finished:=20{'spm_st':=20=
{'spmId':=201,=20'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2390722::DEBUG::2013-01-07=20=
12:13:12,809::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`054ac6c0-f5df-48ed-8db5-a0678f9d37c3`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390722::DEBUG::2013-01-07=20=
12:13:12,809::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390722::DEBUG::2013-01-07=20=
12:13:12,809::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390722::DEBUG::2013-01-07=20=
12:13:12,810::task::957::TaskManager.Task::(_decref)=20=
Task=3D`054ac6c0-f5df-48ed-8db5-a0678f9d37c3`::ref=200=20aborting=20=
False=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,820::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2390723::DEBUG::2013-01-07=20=
12:13:12,820::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`c345b3e5-5fe1-4237-a388-fa119898c5dd`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390723::INFO::2013-01-07=20=
12:13:12,820::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,821::resourceManager::175::ResourceManager.Request::(__init__)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`7db748b2-=
ebf7-4233-878f-e8c6547e51d9`::Request=20was=20made=20in=20=
'/usr/share/vdsm/storage/resourceManager.py'=20line=20'174'=20at=20=
'__init__'=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,821::resourceManager::486::ResourceManager::(registerResource)=20=
Trying=20to=20register=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20for=20lock=20type=20=
'shared'=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,821::resourceManager::528::ResourceManager::(registerResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free.=20=
Now=20locking=20as=20'shared'=20(1=20active=20user)=0A=
Thread-2390723::DEBUG::2013-01-07=20=
12:13:12,821::resourceManager::212::ResourceManager.Request::(grant)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`7db748b2-=
ebf7-4233-878f-e8c6547e51d9`::Granted=20request=0A=
Thread-2390723::DEBUG::2013-01-07=20=
12:13:12,822::task::794::TaskManager.Task::(resourceAcquired)=20=
Task=3D`c345b3e5-5fe1-4237-a388-fa119898c5dd`::_resourcesAcquired:=20=
Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7=20(shared)=0A=
Thread-2390723::DEBUG::2013-01-07=20=
12:13:12,822::task::957::TaskManager.Task::(_decref)=20=
Task=3D`c345b3e5-5fe1-4237-a388-fa119898c5dd`::ref=201=20aborting=20=
False=0AThread-2390723::INFO::2013-01-07=20=
12:13:12,826::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo,=20Return=20response:=20{'info':=20{'spm_id':=201,=20=
'master_uuid':=20'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20=
'Default',=20'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,826::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`c345b3e5-5fe1-4237-a388-fa119898c5dd`::finished:=20{'info':=20=
{'spm_id':=201,=20'master_uuid':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20'Default',=20=
'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,826::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`c345b3e5-5fe1-4237-a388-fa119898c5dd`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,826::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20=
{'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7':=20<=20ResourceRef=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20isValid:=20'True'=20=
obj:=20'None'>}=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,826::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,827::resourceManager::538::ResourceManager::(releaseResource)=20=
Trying=20to=20release=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=0A=
Thread-2390723::DEBUG::2013-01-07=20=
12:13:12,827::resourceManager::553::ResourceManager::(releaseResource)=20=
Released=20resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20=
(0=20active=20users)=0AThread-2390723::DEBUG::2013-01-07=20=
12:13:12,827::resourceManager::558::ResourceManager::(releaseResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free,=20=
finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A=
Thread-2390723::DEBUG::2013-01-07=20=
12:13:12,827::resourceManager::565::ResourceManager::(releaseResource)=20=
No=20one=20is=20waiting=20for=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20Clearing=20records.=0A=
Thread-2390723::DEBUG::2013-01-07=20=
12:13:12,827::task::957::TaskManager.Task::(_decref)=20=
Task=3D`c345b3e5-5fe1-4237-a388-fa119898c5dd`::ref=200=20aborting=20=
False=0AThread-2390726::DEBUG::2013-01-07=20=
12:13:16,575::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.196]::call=20vmGetStats=20with=20=
('cfb17b98-1476-4fbf-9fab-7c7f48b60adf',)=20{}=0A=
Thread-2390726::DEBUG::2013-01-07=20=
12:13:16,580::BindingXMLRPC::890::vds::(wrapper)=20return=20vmGetStats=20=
with=20{'status':=20{'message':=20'Virtual=20machine=20does=20not=20=
exist',=20'code':=201}}=0AThread-2390727::DEBUG::2013-01-07=20=
12:13:16,972::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.196]::call=20vmMigrationCreate=20with=20({'username':=20=
'Unknown',=20'acpiEnable':=20'true',=20'emulatedMachine':=20'pc',=20=
'afterMigrationStatus':=20'Up',=20'vmId':=20=
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf',=20'transparentHugePages':=20=
'true',=20'displaySecurePort':=20'5905',=20'timeOffset':=20-2,=20=
'cpuType':=20'Nehalem',=20'custom':=20{},=20'pauseCode':=20'NOERR',=20=
'migrationDest':=20'libvirt',=20'smp':=20'1',=20'vmType':=20'kvm',=20=
'spiceSslCipherSuite':=20'DEFAULT',=20'_srcDomXML':=20"<domain=20=
type=3D'kvm'=20id=3D'4'>\n=20=20<name>test004.domainname</name>\n=20=20=
<uuid>cfb17b98-1476-4fbf-9fab-7c7f48b60adf</uuid>\n=20=20<memory=20=
unit=3D'KiB'>1048576</memory>\n=20=20<currentMemory=20=
unit=3D'KiB'>1048576</currentMemory>\n=20=20<vcpu=20=
placement=3D'static'>1</vcpu>\n=20=20<cputune>\n=20=20=20=20=
<shares>1020</shares>\n=20=20</cputune>\n=20=20<sysinfo=20=
type=3D'smbios'>\n=20=20=20=20<system>\n=20=20=20=20=20=20<entry=20=
name=3D'manufacturer'>oVirt</entry>\n=20=20=20=20=20=20<entry=20=
name=3D'product'>oVirt=20Node</entry>\n=20=20=20=20=20=20<entry=20=
name=3D'version'>6-3.el6.centos.9</entry>\n=20=20=20=20=20=20<entry=20=
name=3D'serial'>55414E03-C241-11DF-BBDA-64093408D485_d4:85:64:09:34:08</en=
try>\n=20=20=20=20=20=20<entry=20=
name=3D'uuid'>cfb17b98-1476-4fbf-9fab-7c7f48b60adf</entry>\n=20=20=20=20=
</system>\n=20=20</sysinfo>\n=20=20<os>\n=20=20=20=20<type=20=
arch=3D'x86_64'=20machine=3D'rhel6.3.0'>hvm</type>\n=20=20=20=20<boot=20=
dev=3D'hd'/>\n=20=20=20=20<smbios=20mode=3D'sysinfo'/>\n=20=20</os>\n=20=20=
<features>\n=20=20=20=20<acpi/>\n=20=20</features>\n=20=20<cpu=20=
mode=3D'custom'=20match=3D'exact'>\n=20=20=20=20<model=20=
fallback=3D'allow'>Nehalem</model>\n=20=20=20=20<topology=20sockets=3D'1'=20=
cores=3D'1'=20threads=3D'1'/>\n=20=20</cpu>\n=20=20<clock=20=
offset=3D'variable'=20adjustment=3D'-2'>\n=20=20=20=20<timer=20=
name=3D'rtc'=20tickpolicy=3D'catchup'/>\n=20=20</clock>\n=20=20=
<on_poweroff>destroy</on_poweroff>\n=20=20=
<on_reboot>restart</on_reboot>\n=20=20<on_crash>destroy</on_crash>\n=20=20=
<devices>\n=20=20=20=20<emulator>/usr/libexec/qemu-kvm</emulator>\n=20=20=
=20=20<disk=20type=3D'file'=20device=3D'cdrom'>\n=20=20=20=20=20=20=
<driver=20name=3D'qemu'=20type=3D'raw'/>\n=20=20=20=20=20=20<source=20=
file=3D'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f3=
20-4a61-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111/cobb=
ler-base.iso'=20startupPolicy=3D'optional'/>\n=20=20=20=20=20=20<target=20=
dev=3D'hdc'=20bus=3D'ide'/>\n=20=20=20=20=20=20<readonly/>\n=20=20=20=20=20=
=20<serial></serial>\n=20=20=20=20=20=20<alias=20name=3D'ide0-1-0'/>\n=20=
=20=20=20=20=20<address=20type=3D'drive'=20controller=3D'0'=20bus=3D'1'=20=
target=3D'0'=20unit=3D'0'/>\n=20=20=20=20</disk>\n=20=20=20=20<disk=20=
type=3D'file'=20device=3D'disk'=20snapshot=3D'no'>\n=20=20=20=20=20=20=
<driver=20name=3D'qemu'=20type=3D'raw'=20cache=3D'none'=20=
error_policy=3D'stop'=20io=3D'threads'/>\n=20=20=20=20=20=20<source=20=
file=3D'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9f=
a3-4896-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e=
7b27-cdbb-4dc7-ba7b-4285719615d4'/>\n=20=20=20=20=20=20<target=20=
dev=3D'vda'=20bus=3D'virtio'/>\n=20=20=20=20=20=20=
<serial>12a6472f-9ab9-436a-8508-b6721cb2b227</serial>\n=20=20=20=20=20=20=
<alias=20name=3D'virtio-disk0'/>\n=20=20=20=20=20=20<address=20=
type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20slot=3D'0x05'=20=
function=3D'0x0'/>\n=20=20=20=20</disk>\n=20=20=20=20<controller=20=
type=3D'usb'=20index=3D'0'>\n=20=20=20=20=20=20<alias=20name=3D'usb0'/>\n=20=
=20=20=20=20=20<address=20type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20=
slot=3D'0x01'=20function=3D'0x2'/>\n=20=20=20=20</controller>\n=20=20=20=20=
<controller=20type=3D'ide'=20index=3D'0'>\n=20=20=20=20=20=20<alias=20=
name=3D'ide0'/>\n=20=20=20=20=20=20<address=20type=3D'pci'=20=
domain=3D'0x0000'=20bus=3D'0x00'=20slot=3D'0x01'=20function=3D'0x1'/>\n=20=
=20=20=20</controller>\n=20=20=20=20<controller=20type=3D'virtio-serial'=20=
index=3D'0'>\n=20=20=20=20=20=20<alias=20name=3D'virtio-serial0'/>\n=20=20=
=20=20=20=20<address=20type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20=
slot=3D'0x04'=20function=3D'0x0'/>\n=20=20=20=20</controller>\n=20=20=20=20=
<interface=20type=3D'bridge'>\n=20=20=20=20=20=20<mac=20=
address=3D'00:1a:4a:c0:2a:05'/>\n=20=20=20=20=20=20<source=20=
bridge=3D'ovirtmgmt'/>\n=20=20=20=20=20=20<target=20dev=3D'vnet2'/>\n=20=20=
=20=20=20=20<model=20type=3D'virtio'/>\n=20=20=20=20=20=20<alias=20=
name=3D'net0'/>\n=20=20=20=20=20=20<address=20type=3D'pci'=20=
domain=3D'0x0000'=20bus=3D'0x00'=20slot=3D'0x03'=20function=3D'0x0'/>\n=20=
=20=20=20</interface>\n=20=20=20=20<console=20type=3D'pty'=20=
tty=3D'/dev/pts/2'>\n=20=20=20=20=20=20<source=20path=3D'/dev/pts/2'/>\n=20=
=20=20=20=20=20<target=20type=3D'virtio'=20port=3D'0'/>\n=20=20=20=20=20=20=
<alias=20name=3D'console0'/>\n=20=20=20=20</console>\n=20=20=20=20=
<channel=20type=3D'unix'>\n=20=20=20=20=20=20<source=20mode=3D'bind'=20=
path=3D'/var/lib/libvirt/qemu/channels/test004.domainname.redhat.rhevm.vds=
m'/>\n=20=20=20=20=20=20<target=20type=3D'virtio'=20=
name=3D'com.redhat.rhevm.vdsm'/>\n=20=20=20=20=20=20<alias=20=
name=3D'channel0'/>\n=20=20=20=20=20=20<address=20type=3D'virtio-serial'=20=
controller=3D'0'=20bus=3D'0'=20port=3D'1'/>\n=20=20=20=20</channel>\n=20=20=
=20=20<channel=20type=3D'unix'>\n=20=20=20=20=20=20<source=20mode=3D'bind'=
=20=
path=3D'/var/lib/libvirt/qemu/channels/test004.domainname.org.qemu.guest_a=
gent.0'/>\n=20=20=20=20=20=20<target=20type=3D'virtio'=20=
name=3D'org.qemu.guest_agent.0'/>\n=20=20=20=20=20=20<alias=20=
name=3D'channel1'/>\n=20=20=20=20=20=20<address=20type=3D'virtio-serial'=20=
controller=3D'0'=20bus=3D'0'=20port=3D'2'/>\n=20=20=20=20</channel>\n=20=20=
=20=20<channel=20type=3D'spicevmc'>\n=20=20=20=20=20=20<target=20=
type=3D'virtio'=20name=3D'com.redhat.spice.0'/>\n=20=20=20=20=20=20=
<alias=20name=3D'channel2'/>\n=20=20=20=20=20=20<address=20=
type=3D'virtio-serial'=20controller=3D'0'=20bus=3D'0'=20port=3D'3'/>\n=20=
=20=20=20</channel>\n=20=20=20=20<input=20type=3D'mouse'=20bus=3D'ps2'/>\n=
=20=20=20=20<graphics=20type=3D'spice'=20port=3D'5904'=20tlsPort=3D'5905'=20=
autoport=3D'yes'=20keymap=3D'en-us'=20=
passwdValidTo=3D'2012-12-19T15:52:56'=20connected=3D'disconnect'>\n=20=20=
=20=20=20=20<listen=20type=3D'network'=20address=3D'10.192.42.196'=20=
network=3D'vdsm-ovirtmgmt'/>\n=20=20=20=20=20=20<channel=20name=3D'main'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'display'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'inputs'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'cursor'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'playback'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'record'=20=
mode=3D'secure'/>\n=20=20=20=20</graphics>\n=20=20=20=20<video>\n=20=20=20=
=20=20=20<model=20type=3D'qxl'=20vram=3D'65536'=20heads=3D'1'/>\n=20=20=20=
=20=20=20<alias=20name=3D'video0'/>\n=20=20=20=20=20=20<address=20=
type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20slot=3D'0x02'=20=
function=3D'0x0'/>\n=20=20=20=20</video>\n=20=20=20=20<memballoon=20=
model=3D'virtio'>\n=20=20=20=20=20=20<alias=20name=3D'balloon0'/>\n=20=20=
=20=20=20=20<address=20type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20=
slot=3D'0x06'=20function=3D'0x0'/>\n=20=20=20=20</memballoon>\n=20=20=
</devices>\n=20=20<seclabel=20type=3D'none'/>\n</domain>\n",=20=
'memSize':=201024,=20'elapsedTimeOffset':=201626932.6551721096,=20=
'vmName':=20'test004.domainname',=20'nice':=20'0',=20'status':=20'Up',=20=
'clientIp':=20'',=20'displayIp':=20'10.192.42.196',=20'displayPort':=20=
'5904',=20'smpCoresPerSocket':=20'1',=20'spiceSecureChannels':=20=
'smain,sinputs,scursor,splayback,srecord,sdisplay',=20'nicModel':=20=
'rtl8139,pv',=20'keyboardLayout':=20'en-us',=20'kvmEnable':=20'true',=20=
'pitReinjection':=20'false',=20'displayNetwork':=20'ovirtmgmt',=20=
'devices':=20[{'specParams':=20{'vram':=20'65536'},=20'alias':=20=
'video0',=20'deviceId':=20'0f10b02a-f6bc-432d-bc49-478facf49730',=20=
'address':=20{'slot':=20'0x02',=20'bus':=20'0x00',=20'domain':=20=
'0x0000',=20'type':=20'pci',=20'function':=20'0x0'},=20'device':=20=
'qxl',=20'type':=20'video'},=20{'nicModel':=20'pv',=20'macAddr':=20=
'00:1a:4a:c0:2a:05',=20'network':=20'ovirtmgmt',=20'alias':=20'net0',=20=
'specParams':=20{},=20'deviceId':=20=
'376d1987-d374-486d-8a62-d48ab0a47eb1',=20'address':=20{'slot':=20=
'0x03',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20=
'function':=20'0x0'},=20'device':=20'bridge',=20'type':=20'interface',=20=
'name':=20'vnet2'},=20{'target':=201048576,=20'specParams':=20{'model':=20=
'virtio'},=20'alias':=20'balloon0',=20'deviceId':=20=
'72aaa60a-34e5-41e1-80ea-d9b1c3a1b4e2',=20'address':=20{'slot':=20=
'0x06',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20=
'function':=20'0x0'},=20'device':=20'memballoon',=20'type':=20=
'balloon'},=20{'index':=20'2',=20'iface':=20'ide',=20'name':=20'hdc',=20=
'alias':=20'ide0-1-0',=20'shared':=20'false',=20'specParams':=20{'path':=20=
'cobbler-base.iso'},=20'readonly':=20'True',=20'deviceId':=20=
'58cff440-2f4d-4bbe-94d9-d7c12df85c4d',=20'address':=20{'bus':=20'1',=20=
'controller':=20'0',=20'type':=20'drive',=20'target':=20'0',=20'unit':=20=
'0'},=20'device':=20'cdrom',=20'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111/cobbler-bas=
e.iso',=20'type':=20'disk'},=20{'poolID':=20=
'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20'index':=200,=20'iface':=20=
'virtio',=20'apparentsize':=20'21474836480',=20'alias':=20=
'virtio-disk0',=20'imageID':=20'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
'readonly':=20'False',=20'shared':=20'false',=20'truesize':=20'0',=20=
'type':=20'disk',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'reqsize':=20'0',=20'format':=20=
'raw',=20'deviceId':=20'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
'address':=20{'slot':=20'0x05',=20'bus':=20'0x00',=20'domain':=20=
'0x0000',=20'type':=20'pci',=20'function':=20'0x0'},=20'device':=20=
'disk',=20'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'propagateErrors':=20'off',=20'optional':=20=
'false',=20'name':=20'vda',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'specParams':=20{},=20=
'volumeChain':=20[{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'}]},=20{'device':=20'usb',=20=
'alias':=20'usb0',=20'type':=20'controller',=20'address':=20{'slot':=20=
'0x01',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20=
'function':=20'0x2'}},=20{'device':=20'ide',=20'alias':=20'ide0',=20=
'type':=20'controller',=20'address':=20{'slot':=20'0x01',=20'bus':=20=
'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20'function':=20=
'0x1'}},=20{'device':=20'virtio-serial',=20'alias':=20'virtio-serial0',=20=
'type':=20'controller',=20'address':=20{'slot':=20'0x04',=20'bus':=20=
'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20'function':=20=
'0x0'}},=20{'device':=20'unix',=20'alias':=20'channel0',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'1'}},=20{'device':=20'unix',=20=
'alias':=20'channel1',=20'type':=20'channel',=20'address':=20{'bus':=20=
'0',=20'controller':=20'0',=20'type':=20'virtio-serial',=20'port':=20=
'2'}},=20{'device':=20'spicevmc',=20'alias':=20'channel2',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'3'}}],=20'guestIPs':=20'',=20=
'display':=20'qxl'},)=20{}=0AThread-2390727::DEBUG::2013-01-07=20=
12:13:16,972::API::467::vds::(migrationCreate)=20Migration=20create=0A=
Thread-2390727::INFO::2013-01-07=20=
12:13:16,973::clientIF::331::vds::(createVm)=20vmContainerLock=20=
acquired=20by=20vm=20cfb17b98-1476-4fbf-9fab-7c7f48b60adf=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,977::vm::590::vm.Vm::(_startUnderlyingVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Start=0A=
Thread-2390727::DEBUG::2013-01-07=20=
12:13:16,977::clientIF::345::vds::(createVm)=20Total=20desktops=20after=20=
creation=20of=20cfb17b98-1476-4fbf-9fab-7c7f48b60adf=20is=202=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,977::vm::594::vm.Vm::(_startUnderlyingVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::_ongoingCreations=20=
acquired=0AThread-2390727::DEBUG::2013-01-07=20=
12:13:16,978::libvirtvm::2611::vm.Vm::(waitForMigrationDestinationPrepare)=
=20vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration=20=
destination:=20waiting=20for=20VM=20creation=0A=
Thread-2390728::INFO::2013-01-07=20=
12:13:16,978::libvirtvm::1356::vm.Vm::(_run)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::VM=20wrapper=20has=20=
started=0AThread-2390727::DEBUG::2013-01-07=20=
12:13:16,978::libvirtvm::2617::vm.Vm::(waitForMigrationDestinationPrepare)=
=20vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration=20=
destination:=20waiting=2042s=20for=20path=20preparation=0A=
Thread-2390728::WARNING::2013-01-07=20=
12:13:16,978::vm::416::vm.Vm::(getConfDevices)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Unknown=20type=20found,=20=
device:=20'{'device':=20'unix',=20'alias':=20'channel0',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'1'}}'=20found=0A=
Thread-2390728::WARNING::2013-01-07=20=
12:13:16,979::vm::416::vm.Vm::(getConfDevices)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Unknown=20type=20found,=20=
device:=20'{'device':=20'unix',=20'alias':=20'channel1',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'2'}}'=20found=0A=
Thread-2390728::WARNING::2013-01-07=20=
12:13:16,979::vm::416::vm.Vm::(getConfDevices)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Unknown=20type=20found,=20=
device:=20'{'device':=20'spicevmc',=20'alias':=20'channel2',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'3'}}'=20found=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,979::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`7466be2f-f364-49e5-a71d-cdfcbed33fe9`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390728::INFO::2013-01-07=20=
12:13:16,980::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize(sdUUID=3D'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20=
spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
imgUUID=3D'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
volUUID=3D'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20options=3DNone)=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,982::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20732e7b27-cdbb-4dc7-ba7b-4285719615d4=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,985::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20732e7b27-cdbb-4dc7-ba7b-4285719615d4=0A=
Thread-2390728::INFO::2013-01-07=20=
12:13:16,986::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize,=20Return=20response:=20{'truesize':=20'2936401920',=20=
'apparentsize':=20'21474836480'}=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,986::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`7466be2f-f364-49e5-a71d-cdfcbed33fe9`::finished:=20{'truesize':=20=
'2936401920',=20'apparentsize':=20'21474836480'}=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,987::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`7466be2f-f364-49e5-a71d-cdfcbed33fe9`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,987::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,987::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,987::task::957::TaskManager.Task::(_decref)=20=
Task=3D`7466be2f-f364-49e5-a71d-cdfcbed33fe9`::ref=200=20aborting=20=
False=0AThread-2390728::INFO::2013-01-07=20=
12:13:16,987::clientIF::313::vds::(prepareVolumePath)=20prepared=20=
volume=20path:=20=
/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61-=
ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111/cobbler-base=
.iso=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,988::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`c8efa769-fc10-4a04-8b52-45fb26da83c2`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390728::INFO::2013-01-07=20=
12:13:16,988::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
prepareImage(sdUUID=3D'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20=
spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
imgUUID=3D'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
volUUID=3D'732e7b27-cdbb-4dc7-ba7b-4285719615d4')=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,988::resourceManager::175::ResourceManager.Request::(__init__)=20=
ResName=3D`Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7`ReqID=3D`60d2d596-=
761a-4d67-92be-69d29b2ec4f3`::Request=20was=20made=20in=20=
'/usr/share/vdsm/storage/resourceManager.py'=20line=20'174'=20at=20=
'__init__'=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,988::resourceManager::486::ResourceManager::(registerResource)=20=
Trying=20to=20register=20resource=20=
'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=20for=20lock=20type=20=
'shared'=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,989::resourceManager::528::ResourceManager::(registerResource)=20=
Resource=20'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=20is=20free.=20=
Now=20locking=20as=20'shared'=20(1=20active=20user)=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,989::resourceManager::212::ResourceManager.Request::(grant)=20=
ResName=3D`Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7`ReqID=3D`60d2d596-=
761a-4d67-92be-69d29b2ec4f3`::Granted=20request=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,989::task::794::TaskManager.Task::(resourceAcquired)=20=
Task=3D`c8efa769-fc10-4a04-8b52-45fb26da83c2`::_resourcesAcquired:=20=
Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7=20(shared)=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,989::task::957::TaskManager.Task::(_decref)=20=
Task=3D`c8efa769-fc10-4a04-8b52-45fb26da83c2`::ref=201=20aborting=20=
False=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,990::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20732e7b27-cdbb-4dc7-ba7b-4285719615d4=0A=
Thread-2390728::INFO::2013-01-07=20=
12:13:16,995::image::322::Storage.Image::(getChain)=20=
sdUUID=3D2a1939bd-9fa3-4896-b8a9-46234172aae7=20=
imgUUID=3D12a6472f-9ab9-436a-8508-b6721cb2b227=20=
chain=3D[<storage.fileVolume.FileVolume=20object=20at=200x7f7d946190d0>]=20=
=0AThread-2390728::INFO::2013-01-07=20=
12:13:16,996::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
prepareImage,=20Return=20response:=20{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'chain':=20[{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'}]}=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,997::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`c8efa769-fc10-4a04-8b52-45fb26da83c2`::finished:=20{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'chain':=20[{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'}]}=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,997::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`c8efa769-fc10-4a04-8b52-45fb26da83c2`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,997::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20=
{'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7':=20<=20ResourceRef=20=
'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7',=20isValid:=20'True'=20=
obj:=20'None'>}=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,997::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,997::resourceManager::538::ResourceManager::(releaseResource)=20=
Trying=20to=20release=20resource=20=
'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,998::resourceManager::553::ResourceManager::(releaseResource)=20=
Released=20resource=20'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=20=
(0=20active=20users)=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:16,998::resourceManager::558::ResourceManager::(releaseResource)=20=
Resource=20'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=20is=20free,=20=
finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,998::resourceManager::565::ResourceManager::(releaseResource)=20=
No=20one=20is=20waiting=20for=20resource=20=
'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7',=20Clearing=20records.=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:16,998::task::957::TaskManager.Task::(_decref)=20=
Task=3D`c8efa769-fc10-4a04-8b52-45fb26da83c2`::ref=200=20aborting=20=
False=0AThread-2390728::INFO::2013-01-07=20=
12:13:16,998::clientIF::313::vds::(prepareVolumePath)=20prepared=20=
volume=20path:=20=
/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896-=
b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cdb=
b-4dc7-ba7b-4285719615d4=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:17,002::misc::83::Storage.Misc.excCmd::(<lambda>)=20'/usr/bin/sudo=20=
-n=20/sbin/service=20ksmtuned=20retune'=20(cwd=20None)=0A=
Thread-2390727::DEBUG::2013-01-07=20=
12:13:17,003::API::480::vds::(migrationCreate)=20Destination=20VM=20=
creation=20succeeded=0AThread-2390727::DEBUG::2013-01-07=20=
12:13:17,010::BindingXMLRPC::890::vds::(wrapper)=20return=20=
vmMigrationCreate=20with=20{'status':=20{'message':=20'Done',=20'code':=20=
0},=20'migrationPort':=200,=20'params':=20{'status':=20'Migration=20=
Destination',=20'acpiEnable':=20'true',=20'emulatedMachine':=20'pc',=20=
'afterMigrationStatus':=20'Up',=20'pid':=20'0',=20=
'transparentHugePages':=20'true',=20'displaySecurePort':=20'-1',=20=
'timeOffset':=20-2,=20'cpuType':=20'Nehalem',=20'smp':=20'1',=20=
'pauseCode':=20'NOERR',=20'migrationDest':=20'libvirt',=20'custom':=20=
{},=20'vmType':=20'kvm',=20'spiceSslCipherSuite':=20'DEFAULT',=20=
'memSize':=201024,=20'vmName':=20'test004.domainname',=20'nice':=20'0',=20=
'username':=20'Unknown',=20'vmId':=20=
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf',=20'displayIp':=20=
'10.192.42.165',=20'keyboardLayout':=20'en-us',=20'displayPort':=20'-1',=20=
'guestIPs':=20'',=20'spiceSecureChannels':=20=
'smain,sinputs,scursor,splayback,srecord,sdisplay',=20'nicModel':=20=
'rtl8139,pv',=20'smpCoresPerSocket':=20'1',=20'kvmEnable':=20'true',=20=
'pitReinjection':=20'false',=20'displayNetwork':=20'ovirtmgmt',=20=
'devices':=20[{'device':=20'usb',=20'alias':=20'usb0',=20'type':=20=
'controller',=20'address':=20{'slot':=20'0x01',=20'bus':=20'0x00',=20=
'domain':=20'0x0000',=20'type':=20'pci',=20'function':=20'0x2'}},=20=
{'device':=20'ide',=20'alias':=20'ide0',=20'type':=20'controller',=20=
'address':=20{'slot':=20'0x01',=20'bus':=20'0x00',=20'domain':=20=
'0x0000',=20'type':=20'pci',=20'function':=20'0x1'}},=20{'device':=20=
'virtio-serial',=20'alias':=20'virtio-serial0',=20'type':=20=
'controller',=20'address':=20{'slot':=20'0x04',=20'bus':=20'0x00',=20=
'domain':=20'0x0000',=20'type':=20'pci',=20'function':=20'0x0'}},=20=
{'specParams':=20{'vram':=20'65536'},=20'alias':=20'video0',=20=
'deviceId':=20'0f10b02a-f6bc-432d-bc49-478facf49730',=20'address':=20=
{'slot':=20'0x02',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20=
'pci',=20'function':=20'0x0'},=20'device':=20'qxl',=20'type':=20=
'video'},=20{'nicModel':=20'pv',=20'macAddr':=20'00:1a:4a:c0:2a:05',=20=
'network':=20'ovirtmgmt',=20'alias':=20'net0',=20'specParams':=20{},=20=
'deviceId':=20'376d1987-d374-486d-8a62-d48ab0a47eb1',=20'address':=20=
{'slot':=20'0x03',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20=
'pci',=20'function':=20'0x0'},=20'device':=20'bridge',=20'type':=20=
'interface',=20'name':=20'vnet2'},=20{'target':=201048576,=20=
'specParams':=20{'model':=20'virtio'},=20'alias':=20'balloon0',=20=
'deviceId':=20'72aaa60a-34e5-41e1-80ea-d9b1c3a1b4e2',=20'address':=20=
{'slot':=20'0x06',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20=
'pci',=20'function':=20'0x0'},=20'device':=20'memballoon',=20'type':=20=
'balloon'},=20{'index':=20'2',=20'iface':=20'ide',=20'name':=20'hdc',=20=
'alias':=20'ide0-1-0',=20'shared':=20'false',=20'specParams':=20{'path':=20=
'cobbler-base.iso'},=20'readonly':=20'True',=20'deviceId':=20=
'58cff440-2f4d-4bbe-94d9-d7c12df85c4d',=20'address':=20{'bus':=20'1',=20=
'controller':=20'0',=20'type':=20'drive',=20'target':=20'0',=20'unit':=20=
'0'},=20'device':=20'cdrom',=20'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111/cobbler-bas=
e.iso',=20'type':=20'disk'},=20{'poolID':=20=
'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20'index':=200,=20'iface':=20=
'virtio',=20'apparentsize':=20'21474836480',=20'alias':=20=
'virtio-disk0',=20'imageID':=20'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
'readonly':=20'False',=20'shared':=20'false',=20'truesize':=20=
'2936401920',=20'type':=20'disk',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'reqsize':=20'0',=20'format':=20=
'raw',=20'deviceId':=20'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
'address':=20{'slot':=20'0x05',=20'bus':=20'0x00',=20'domain':=20=
'0x0000',=20'type':=20'pci',=20'function':=20'0x0'},=20'device':=20=
'disk',=20'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'propagateErrors':=20'off',=20'optional':=20=
'false',=20'name':=20'vda',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'specParams':=20{},=20=
'volumeChain':=20[{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'}]},=20{'device':=20'unix',=20=
'alias':=20'channel0',=20'type':=20'channel',=20'address':=20{'bus':=20=
'0',=20'controller':=20'0',=20'type':=20'virtio-serial',=20'port':=20=
'1'}},=20{'device':=20'unix',=20'alias':=20'channel1',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'2'}},=20{'device':=20'spicevmc',=20=
'alias':=20'channel2',=20'type':=20'channel',=20'address':=20{'bus':=20=
'0',=20'controller':=20'0',=20'type':=20'virtio-serial',=20'port':=20=
'3'}}],=20'clientIp':=20'',=20'display':=20'qxl'}}=0A=
Thread-2390728::DEBUG::2013-01-07=20=
12:13:17,035::misc::83::Storage.Misc.excCmd::(<lambda>)=20SUCCESS:=20=
<err>=20=3D=20'';=20<rc>=20=3D=200=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:17,036::vm::611::vm.Vm::(_startUnderlyingVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::_ongoingCreations=20=
released=0AThread-2390728::DEBUG::2013-01-07=20=
12:13:17,036::libvirtvm::1669::vm.Vm::(_waitForIncomingMigrationFinish)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Waiting=20300=20seconds=20=
for=20end=20of=20migration=0AThread-12621::DEBUG::2013-01-07=20=
12:13:17,148::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`3d3eb9e9-9c85-410e-a679-cf50f2ac763e`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-12621::INFO::2013-01-07=20=
12:13:17,149::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize(sdUUID=3D'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20=
spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
imgUUID=3D'024845f8-ebda-4f74-85c4-c8525eb3ce87',=20=
volUUID=3D'cec87811-89c8-4daa-a49b-ee870c79db73',=20options=3DNone)=0A=
Thread-12621::DEBUG::2013-01-07=20=
12:13:17,150::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20cec87811-89c8-4daa-a49b-ee870c79db73=0A=
Thread-12621::DEBUG::2013-01-07=20=
12:13:17,169::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20cec87811-89c8-4daa-a49b-ee870c79db73=0A=
Thread-12621::INFO::2013-01-07=20=
12:13:17,171::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize,=20Return=20response:=20{'truesize':=20'10737422336',=20=
'apparentsize':=20'10737418240'}=0AThread-12621::DEBUG::2013-01-07=20=
12:13:17,171::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`3d3eb9e9-9c85-410e-a679-cf50f2ac763e`::finished:=20{'truesize':=20=
'10737422336',=20'apparentsize':=20'10737418240'}=0A=
Thread-12621::DEBUG::2013-01-07=20=
12:13:17,171::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`3d3eb9e9-9c85-410e-a679-cf50f2ac763e`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-12621::DEBUG::2013-01-07=20=
12:13:17,171::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-12621::DEBUG::2013-01-07=20=
12:13:17,171::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-12621::DEBUG::2013-01-07=20=
12:13:17,172::task::957::TaskManager.Task::(_decref)=20=
Task=3D`3d3eb9e9-9c85-410e-a679-cf50f2ac763e`::ref=200=20aborting=20=
False=0AThread-2390731::DEBUG::2013-01-07=20=
12:13:17,393::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.207]::call=20vmGetStats=20with=20=
('cfb17b98-1476-4fbf-9fab-7c7f48b60adf',)=20{}=0A=
Thread-2390731::DEBUG::2013-01-07=20=
12:13:17,393::BindingXMLRPC::890::vds::(wrapper)=20return=20vmGetStats=20=
with=20{'status':=20{'message':=20'Done',=20'code':=200},=20'statsList':=20=
[{'status':=20'Migration=20Destination',=20'hash':=20'0',=20=
'acpiEnable':=20'true',=20'pid':=20'0',=20'displayIp':=20=
'10.192.42.165',=20'displayPort':=20'-1',=20'displaySecurePort':=20'-1',=20=
'timeOffset':=20-2,=20'pauseCode':=20'NOERR',=20'kvmEnable':=20'true',=20=
'network':=20{},=20'vmId':=20'cfb17b98-1476-4fbf-9fab-7c7f48b60adf',=20=
'displayType':=20'qxl',=20'disks':=20{},=20'monitorResponse':=20'0',=20=
'elapsedTime':=20'1626933',=20'vmType':=20'kvm',=20'clientIp':=20''}]}=0A=
Thread-2390732::DEBUG::2013-01-07=20=
12:13:17,685::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.196]::call=20vmDestroy=20with=20=
('cfb17b98-1476-4fbf-9fab-7c7f48b60adf',)=20{}=0A=
Thread-2390732::INFO::2013-01-07=20=
12:13:17,685::API::308::vds::(destroy)=20vmContainerLock=20acquired=20by=20=
vm=20cfb17b98-1476-4fbf-9fab-7c7f48b60adf=0A=
Thread-2390732::DEBUG::2013-01-07=20=
12:13:17,686::libvirtvm::2209::vm.Vm::(destroy)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::destroy=20Called=0A=
Thread-2390732::INFO::2013-01-07=20=
12:13:17,686::libvirtvm::2160::vm.Vm::(releaseVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Release=20VM=20resources=0A=
Thread-2390732::DEBUG::2013-01-07=20=
12:13:17,686::misc::83::Storage.Misc.excCmd::(<lambda>)=20'/usr/bin/sudo=20=
-n=20/sbin/service=20ksmtuned=20retune'=20(cwd=20None)=0A=
Thread-2390732::DEBUG::2013-01-07=20=
12:13:17,726::misc::83::Storage.Misc.excCmd::(<lambda>)=20SUCCESS:=20=
<err>=20=3D=20'';=20<rc>=20=3D=200=0AThread-2390732::DEBUG::2013-01-07=20=
12:13:17,727::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`d8fca4ca-621a-4652-8c2c-fae51778e6d1`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390732::INFO::2013-01-07=20=
12:13:17,727::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
inappropriateDevices(thiefId=3D'cfb17b98-1476-4fbf-9fab-7c7f48b60adf')=0A=
Thread-2390732::INFO::2013-01-07=20=
12:13:17,729::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
inappropriateDevices,=20Return=20response:=20None=0A=
Thread-2390732::DEBUG::2013-01-07=20=
12:13:17,730::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`d8fca4ca-621a-4652-8c2c-fae51778e6d1`::finished:=20None=0A=
Thread-2390732::DEBUG::2013-01-07=20=
12:13:17,730::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`d8fca4ca-621a-4652-8c2c-fae51778e6d1`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390732::DEBUG::2013-01-07=20=
12:13:17,730::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390732::DEBUG::2013-01-07=20=
12:13:17,730::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390732::DEBUG::2013-01-07=20=
12:13:17,730::task::957::TaskManager.Task::(_decref)=20=
Task=3D`d8fca4ca-621a-4652-8c2c-fae51778e6d1`::ref=200=20aborting=20=
False=0AThread-2390732::DEBUG::2013-01-07=20=
12:13:17,731::libvirtvm::2203::vm.Vm::(deleteVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Total=20desktops=20after=20=
destroy=20of=20cfb17b98-1476-4fbf-9fab-7c7f48b60adf=20is=201=0A=
Thread-2390732::DEBUG::2013-01-07=20=
12:13:17,731::BindingXMLRPC::890::vds::(wrapper)=20return=20vmDestroy=20=
with=20{'status':=20{'message':=20'Machine=20destroyed',=20'code':=200}}=0A=
Thread-2390734::DEBUG::2013-01-07=20=
12:13:21,438::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`1d0b3f03-6f40-48c1-8813-e272d6fc7af4`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390734::INFO::2013-01-07=20=
12:13:21,438::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats(options=3DNone)=0AThread-2390734::INFO::2013-01-07=20=
12:13:21,439::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats,=20Return=20response:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00211310386658',=20'lastCheck':=20'4.6',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00226402282715',=20'lastCheck':=20'7.3',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00216794013977',=20'lastCheck':=20'7.2',=20'code':=200,=20'valid':=20=
True}}=0AThread-2390734::DEBUG::2013-01-07=20=
12:13:21,439::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`1d0b3f03-6f40-48c1-8813-e272d6fc7af4`::finished:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00211310386658',=20'lastCheck':=20'4.6',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00226402282715',=20'lastCheck':=20'7.3',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00216794013977',=20'lastCheck':=20'7.2',=20'code':=200,=20'valid':=20=
True}}=0AThread-2390734::DEBUG::2013-01-07=20=
12:13:21,439::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`1d0b3f03-6f40-48c1-8813-e272d6fc7af4`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390734::DEBUG::2013-01-07=20=
12:13:21,439::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390734::DEBUG::2013-01-07=20=
12:13:21,439::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390734::DEBUG::2013-01-07=20=
12:13:21,439::task::957::TaskManager.Task::(_decref)=20=
Task=3D`1d0b3f03-6f40-48c1-8813-e272d6fc7af4`::ref=200=20aborting=20=
False=0AThread-2390735::DEBUG::2013-01-07=20=
12:13:21,453::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`a08884f6-d634-4d1d-a0ef-f77cd96f0953`::Disk=20vda=20latency=20=
not=20available=0AThread-2390736::DEBUG::2013-01-07=20=
12:13:22,932::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2390736::DEBUG::2013-01-07=20=
12:13:22,932::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`c8bd5b6e-553b-49b7-b4ac-ae89b70f4ad6`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390736::INFO::2013-01-07=20=
12:13:22,932::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2390736::INFO::2013-01-07=20=
12:13:22,933::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus,=20Return=20response:=20{'spm_st':=20{'spmId':=201,=20=
'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2390736::DEBUG::2013-01-07=20=
12:13:22,933::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`c8bd5b6e-553b-49b7-b4ac-ae89b70f4ad6`::finished:=20{'spm_st':=20=
{'spmId':=201,=20'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2390736::DEBUG::2013-01-07=20=
12:13:22,933::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`c8bd5b6e-553b-49b7-b4ac-ae89b70f4ad6`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390736::DEBUG::2013-01-07=20=
12:13:22,933::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390736::DEBUG::2013-01-07=20=
12:13:22,933::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390736::DEBUG::2013-01-07=20=
12:13:22,934::task::957::TaskManager.Task::(_decref)=20=
Task=3D`c8bd5b6e-553b-49b7-b4ac-ae89b70f4ad6`::ref=200=20aborting=20=
False=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,944::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2390737::DEBUG::2013-01-07=20=
12:13:22,944::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`0488b8ac-6c6a-4d18-ad09-f2bacdb5126e`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390737::INFO::2013-01-07=20=
12:13:22,944::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,945::resourceManager::175::ResourceManager.Request::(__init__)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`7bed9027-=
0cb9-4317-af0b-5beaec3bb02b`::Request=20was=20made=20in=20=
'/usr/share/vdsm/storage/resourceManager.py'=20line=20'174'=20at=20=
'__init__'=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,945::resourceManager::486::ResourceManager::(registerResource)=20=
Trying=20to=20register=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20for=20lock=20type=20=
'shared'=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,945::resourceManager::528::ResourceManager::(registerResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free.=20=
Now=20locking=20as=20'shared'=20(1=20active=20user)=0A=
Thread-2390737::DEBUG::2013-01-07=20=
12:13:22,946::resourceManager::212::ResourceManager.Request::(grant)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`7bed9027-=
0cb9-4317-af0b-5beaec3bb02b`::Granted=20request=0A=
Thread-2390737::DEBUG::2013-01-07=20=
12:13:22,946::task::794::TaskManager.Task::(resourceAcquired)=20=
Task=3D`0488b8ac-6c6a-4d18-ad09-f2bacdb5126e`::_resourcesAcquired:=20=
Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7=20(shared)=0A=
Thread-2390737::DEBUG::2013-01-07=20=
12:13:22,946::task::957::TaskManager.Task::(_decref)=20=
Task=3D`0488b8ac-6c6a-4d18-ad09-f2bacdb5126e`::ref=201=20aborting=20=
False=0AThread-2390737::INFO::2013-01-07=20=
12:13:22,951::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo,=20Return=20response:=20{'info':=20{'spm_id':=201,=20=
'master_uuid':=20'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20=
'Default',=20'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,951::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`0488b8ac-6c6a-4d18-ad09-f2bacdb5126e`::finished:=20{'info':=20=
{'spm_id':=201,=20'master_uuid':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20'Default',=20=
'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,951::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`0488b8ac-6c6a-4d18-ad09-f2bacdb5126e`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,951::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20=
{'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7':=20<=20ResourceRef=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20isValid:=20'True'=20=
obj:=20'None'>}=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,951::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,952::resourceManager::538::ResourceManager::(releaseResource)=20=
Trying=20to=20release=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=0A=
Thread-2390737::DEBUG::2013-01-07=20=
12:13:22,952::resourceManager::553::ResourceManager::(releaseResource)=20=
Released=20resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20=
(0=20active=20users)=0AThread-2390737::DEBUG::2013-01-07=20=
12:13:22,952::resourceManager::558::ResourceManager::(releaseResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free,=20=
finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A=
Thread-2390737::DEBUG::2013-01-07=20=
12:13:22,952::resourceManager::565::ResourceManager::(releaseResource)=20=
No=20one=20is=20waiting=20for=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20Clearing=20records.=0A=
Thread-2390737::DEBUG::2013-01-07=20=
12:13:22,952::task::957::TaskManager.Task::(_decref)=20=
Task=3D`0488b8ac-6c6a-4d18-ad09-f2bacdb5126e`::ref=200=20aborting=20=
False=0AThread-2390742::DEBUG::2013-01-07=20=
12:13:31,612::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`e0222004-6205-4369-b072-b3ce4dea1ac4`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390742::INFO::2013-01-07=20=
12:13:31,612::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats(options=3DNone)=0AThread-2390742::INFO::2013-01-07=20=
12:13:31,613::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats,=20Return=20response:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00247502326965',=20'lastCheck':=20'4.8',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.002277135849',=20'lastCheck':=20'7.5',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00219702720642',=20'lastCheck':=20'7.4',=20'code':=200,=20'valid':=20=
True}}=0AThread-2390742::DEBUG::2013-01-07=20=
12:13:31,613::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`e0222004-6205-4369-b072-b3ce4dea1ac4`::finished:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00247502326965',=20'lastCheck':=20'4.8',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.002277135849',=20'lastCheck':=20'7.5',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00219702720642',=20'lastCheck':=20'7.4',=20'code':=200,=20'valid':=20=
True}}=0AThread-2390742::DEBUG::2013-01-07=20=
12:13:31,613::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`e0222004-6205-4369-b072-b3ce4dea1ac4`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390742::DEBUG::2013-01-07=20=
12:13:31,613::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390742::DEBUG::2013-01-07=20=
12:13:31,613::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390742::DEBUG::2013-01-07=20=
12:13:31,614::task::957::TaskManager.Task::(_decref)=20=
Task=3D`e0222004-6205-4369-b072-b3ce4dea1ac4`::ref=200=20aborting=20=
False=0AThread-2390743::DEBUG::2013-01-07=20=
12:13:31,626::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`a08884f6-d634-4d1d-a0ef-f77cd96f0953`::Disk=20vda=20latency=20=
not=20available=0AThread-2390744::DEBUG::2013-01-07=20=
12:13:33,032::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2390744::DEBUG::2013-01-07=20=
12:13:33,032::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`984bf1f7-c605-49df-91f1-ebf69624a5e1`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390744::INFO::2013-01-07=20=
12:13:33,032::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2390744::INFO::2013-01-07=20=
12:13:33,033::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus,=20Return=20response:=20{'spm_st':=20{'spmId':=201,=20=
'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2390744::DEBUG::2013-01-07=20=
12:13:33,033::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`984bf1f7-c605-49df-91f1-ebf69624a5e1`::finished:=20{'spm_st':=20=
{'spmId':=201,=20'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2390744::DEBUG::2013-01-07=20=
12:13:33,033::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`984bf1f7-c605-49df-91f1-ebf69624a5e1`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390744::DEBUG::2013-01-07=20=
12:13:33,033::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390744::DEBUG::2013-01-07=20=
12:13:33,033::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390744::DEBUG::2013-01-07=20=
12:13:33,033::task::957::TaskManager.Task::(_decref)=20=
Task=3D`984bf1f7-c605-49df-91f1-ebf69624a5e1`::ref=200=20aborting=20=
False=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,044::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2390745::DEBUG::2013-01-07=20=
12:13:33,044::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`fdc15232-1311-4ca5-aed0-01716d137963`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390745::INFO::2013-01-07=20=
12:13:33,044::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,045::resourceManager::175::ResourceManager.Request::(__init__)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`bfe0adcf-=
6b5d-4970-9916-7bcbdc083569`::Request=20was=20made=20in=20=
'/usr/share/vdsm/storage/resourceManager.py'=20line=20'174'=20at=20=
'__init__'=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,045::resourceManager::486::ResourceManager::(registerResource)=20=
Trying=20to=20register=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20for=20lock=20type=20=
'shared'=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,045::resourceManager::528::ResourceManager::(registerResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free.=20=
Now=20locking=20as=20'shared'=20(1=20active=20user)=0A=
Thread-2390745::DEBUG::2013-01-07=20=
12:13:33,045::resourceManager::212::ResourceManager.Request::(grant)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`bfe0adcf-=
6b5d-4970-9916-7bcbdc083569`::Granted=20request=0A=
Thread-2390745::DEBUG::2013-01-07=20=
12:13:33,046::task::794::TaskManager.Task::(resourceAcquired)=20=
Task=3D`fdc15232-1311-4ca5-aed0-01716d137963`::_resourcesAcquired:=20=
Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7=20(shared)=0A=
Thread-2390745::DEBUG::2013-01-07=20=
12:13:33,046::task::957::TaskManager.Task::(_decref)=20=
Task=3D`fdc15232-1311-4ca5-aed0-01716d137963`::ref=201=20aborting=20=
False=0AThread-2390745::INFO::2013-01-07=20=
12:13:33,049::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo,=20Return=20response:=20{'info':=20{'spm_id':=201,=20=
'master_uuid':=20'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20=
'Default',=20'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,050::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`fdc15232-1311-4ca5-aed0-01716d137963`::finished:=20{'info':=20=
{'spm_id':=201,=20'master_uuid':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20'Default',=20=
'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,050::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`fdc15232-1311-4ca5-aed0-01716d137963`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,050::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20=
{'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7':=20<=20ResourceRef=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20isValid:=20'True'=20=
obj:=20'None'>}=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,050::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,050::resourceManager::538::ResourceManager::(releaseResource)=20=
Trying=20to=20release=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=0A=
Thread-2390745::DEBUG::2013-01-07=20=
12:13:33,051::resourceManager::553::ResourceManager::(releaseResource)=20=
Released=20resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20=
(0=20active=20users)=0AThread-2390745::DEBUG::2013-01-07=20=
12:13:33,051::resourceManager::558::ResourceManager::(releaseResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free,=20=
finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A=
Thread-2390745::DEBUG::2013-01-07=20=
12:13:33,051::resourceManager::565::ResourceManager::(releaseResource)=20=
No=20one=20is=20waiting=20for=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20Clearing=20records.=0A=
Thread-2390745::DEBUG::2013-01-07=20=
12:13:33,051::task::957::TaskManager.Task::(_decref)=20=
Task=3D`fdc15232-1311-4ca5-aed0-01716d137963`::ref=200=20aborting=20=
False=0AThread-2390750::DEBUG::2013-01-07=20=
12:13:41,773::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`bce4c21e-17ac-4aaa-9ff5-6685b8e6dae7`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390750::INFO::2013-01-07=20=
12:13:41,774::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats(options=3DNone)=0AThread-2390750::INFO::2013-01-07=20=
12:13:41,774::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats,=20Return=20response:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00256395339966',=20'lastCheck':=20'4.9',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00182700157166',=20'lastCheck':=20'7.7',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00169897079468',=20'lastCheck':=20'7.5',=20'code':=200,=20'valid':=20=
True}}=0AThread-2390750::DEBUG::2013-01-07=20=
12:13:41,774::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`bce4c21e-17ac-4aaa-9ff5-6685b8e6dae7`::finished:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00256395339966',=20'lastCheck':=20'4.9',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00182700157166',=20'lastCheck':=20'7.7',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00169897079468',=20'lastCheck':=20'7.5',=20'code':=200,=20'valid':=20=
True}}=0AThread-2390750::DEBUG::2013-01-07=20=
12:13:41,774::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`bce4c21e-17ac-4aaa-9ff5-6685b8e6dae7`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390750::DEBUG::2013-01-07=20=
12:13:41,775::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390750::DEBUG::2013-01-07=20=
12:13:41,775::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390750::DEBUG::2013-01-07=20=
12:13:41,775::task::957::TaskManager.Task::(_decref)=20=
Task=3D`bce4c21e-17ac-4aaa-9ff5-6685b8e6dae7`::ref=200=20aborting=20=
False=0AThread-2390751::DEBUG::2013-01-07=20=
12:13:41,788::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`a08884f6-d634-4d1d-a0ef-f77cd96f0953`::Disk=20vda=20latency=20=
not=20available=0AThread-2390752::DEBUG::2013-01-07=20=
12:13:43,131::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2390752::DEBUG::2013-01-07=20=
12:13:43,132::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`7368bb35-b085-4fde-858d-d7945df1f6a5`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390752::INFO::2013-01-07=20=
12:13:43,132::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2390752::INFO::2013-01-07=20=
12:13:43,132::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus,=20Return=20response:=20{'spm_st':=20{'spmId':=201,=20=
'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2390752::DEBUG::2013-01-07=20=
12:13:43,132::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`7368bb35-b085-4fde-858d-d7945df1f6a5`::finished:=20{'spm_st':=20=
{'spmId':=201,=20'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2390752::DEBUG::2013-01-07=20=
12:13:43,133::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`7368bb35-b085-4fde-858d-d7945df1f6a5`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390752::DEBUG::2013-01-07=20=
12:13:43,133::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2390752::DEBUG::2013-01-07=20=
12:13:43,133::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390752::DEBUG::2013-01-07=20=
12:13:43,133::task::957::TaskManager.Task::(_decref)=20=
Task=3D`7368bb35-b085-4fde-858d-d7945df1f6a5`::ref=200=20aborting=20=
False=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,143::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2390753::DEBUG::2013-01-07=20=
12:13:43,144::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`98135fe0-6b39-4fab-b347-98543cf54bc6`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2390753::INFO::2013-01-07=20=
12:13:43,144::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,144::resourceManager::175::ResourceManager.Request::(__init__)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`0867c186-=
db83-4573-b843-63d2737ffaff`::Request=20was=20made=20in=20=
'/usr/share/vdsm/storage/resourceManager.py'=20line=20'174'=20at=20=
'__init__'=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,144::resourceManager::486::ResourceManager::(registerResource)=20=
Trying=20to=20register=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20for=20lock=20type=20=
'shared'=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,145::resourceManager::528::ResourceManager::(registerResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free.=20=
Now=20locking=20as=20'shared'=20(1=20active=20user)=0A=
Thread-2390753::DEBUG::2013-01-07=20=
12:13:43,145::resourceManager::212::ResourceManager.Request::(grant)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`0867c186-=
db83-4573-b843-63d2737ffaff`::Granted=20request=0A=
Thread-2390753::DEBUG::2013-01-07=20=
12:13:43,145::task::794::TaskManager.Task::(resourceAcquired)=20=
Task=3D`98135fe0-6b39-4fab-b347-98543cf54bc6`::_resourcesAcquired:=20=
Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7=20(shared)=0A=
Thread-2390753::DEBUG::2013-01-07=20=
12:13:43,145::task::957::TaskManager.Task::(_decref)=20=
Task=3D`98135fe0-6b39-4fab-b347-98543cf54bc6`::ref=201=20aborting=20=
False=0AThread-2390753::INFO::2013-01-07=20=
12:13:43,149::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo,=20Return=20response:=20{'info':=20{'spm_id':=201,=20=
'master_uuid':=20'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20=
'Default',=20'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,149::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`98135fe0-6b39-4fab-b347-98543cf54bc6`::finished:=20{'info':=20=
{'spm_id':=201,=20'master_uuid':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20'Default',=20=
'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,149::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`98135fe0-6b39-4fab-b347-98543cf54bc6`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,149::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20=
{'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7':=20<=20ResourceRef=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20isValid:=20'True'=20=
obj:=20'None'>}=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,150::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,150::resourceManager::538::ResourceManager::(releaseResource)=20=
Trying=20to=20release=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=0A=
Thread-2390753::DEBUG::2013-01-07=20=
12:13:43,150::resourceManager::553::ResourceManager::(releaseResource)=20=
Released=20resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20=
(0=20active=20users)=0AThread-2390753::DEBUG::2013-01-07=20=
12:13:43,150::resourceManager::558::ResourceManager::(releaseResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free,=20=
finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A=
Thread-2390753::DEBUG::2013-01-07=20=
12:13:43,150::resourceManager::565::ResourceManager::(releaseResource)=20=
No=20one=20is=20waiting=20for=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20Clearing=20records.=0A=
Thread-2390753::DEBUG::2013-01-07=20=
12:13:43,151::task::957::TaskManager.Task::(_decref)=20=
Task=3D`98135fe0-6b39-4fab-b347-98543cf54bc6`::ref=200=20aborting=20=
False=0A=
--Apple-Mail=_B91DF312-1386-4884-ADD0-7FF314F05FC2--
2:56 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
On 01/07/2013 01:18 PM, Tom Brown wrote:
> VDSM is the virtualization agent. look at /var/log/vdsm/vdsm.log
many thanks - attached is the snip of that log when i try the migration
thanks
can you attach the same snip from the src VDSM 10.192.42.196 as well?
3:50 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
--Apple-Mail=_C82D1F4B-8BD2-4AB4-8D7E-7DAE9D5676F1
Content-Transfer-Encoding: quoted-printable
Content-Type: text/plain;
charset=iso-8859-1
can you attach the same snip from the src VDSM 10.192.42.196 as well?
The log is pretty chatty therefore i did another migration attempt and =
snipd'd the new=20=
--Apple-Mail=_C82D1F4B-8BD2-4AB4-8D7E-7DAE9D5676F1
Content-Disposition: attachment;
filename=migrate-dest.log
Content-Type: application/octet-stream;
name="migrate-dest.log"
Content-Transfer-Encoding: quoted-printable
Thread-2456765::DEBUG::2013-01-08=20=
10:42:20,119::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2456765::DEBUG::2013-01-08=20=
10:42:20,119::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`d9cc7d0f-4fa3-4374-9b65-232df90c5b73`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2456765::INFO::2013-01-08=20=
10:42:20,119::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2456765::INFO::2013-01-08=20=
10:42:20,120::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getSpmStatus,=20Return=20response:=20{'spm_st':=20{'spmId':=201,=20=
'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2456765::DEBUG::2013-01-08=20=
10:42:20,120::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`d9cc7d0f-4fa3-4374-9b65-232df90c5b73`::finished:=20{'spm_st':=20=
{'spmId':=201,=20'spmStatus':=20'SPM',=20'spmLver':=200}}=0A=
Thread-2456765::DEBUG::2013-01-08=20=
10:42:20,120::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`d9cc7d0f-4fa3-4374-9b65-232df90c5b73`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2456765::DEBUG::2013-01-08=20=
10:42:20,120::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2456765::DEBUG::2013-01-08=20=
10:42:20,120::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2456765::DEBUG::2013-01-08=20=
10:42:20,121::task::957::TaskManager.Task::(_decref)=20=
Task=3D`d9cc7d0f-4fa3-4374-9b65-232df90c5b73`::ref=200=20aborting=20=
False=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,131::BindingXMLRPC::161::vds::(wrapper)=20[10.192.42.207]=0A=
Thread-2456766::DEBUG::2013-01-08=20=
10:42:20,131::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`e84910c4-d6fb-4907-a445-0751d91d715f`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2456766::INFO::2013-01-08=20=
10:42:20,132::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo(spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
options=3DNone)=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,132::resourceManager::175::ResourceManager.Request::(__init__)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`f3f58cc3-=
e5b9-4a3f-8370-b812e40d62cb`::Request=20was=20made=20in=20=
'/usr/share/vdsm/storage/resourceManager.py'=20line=20'174'=20at=20=
'__init__'=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,132::resourceManager::486::ResourceManager::(registerResource)=20=
Trying=20to=20register=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20for=20lock=20type=20=
'shared'=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,132::resourceManager::528::ResourceManager::(registerResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free.=20=
Now=20locking=20as=20'shared'=20(1=20active=20user)=0A=
Thread-2456766::DEBUG::2013-01-08=20=
10:42:20,133::resourceManager::212::ResourceManager.Request::(grant)=20=
ResName=3D`Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7`ReqID=3D`f3f58cc3-=
e5b9-4a3f-8370-b812e40d62cb`::Granted=20request=0A=
Thread-2456766::DEBUG::2013-01-08=20=
10:42:20,133::task::794::TaskManager.Task::(resourceAcquired)=20=
Task=3D`e84910c4-d6fb-4907-a445-0751d91d715f`::_resourcesAcquired:=20=
Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7=20(shared)=0A=
Thread-2456766::DEBUG::2013-01-08=20=
10:42:20,133::task::957::TaskManager.Task::(_decref)=20=
Task=3D`e84910c4-d6fb-4907-a445-0751d91d715f`::ref=201=20aborting=20=
False=0AThread-2456766::INFO::2013-01-08=20=
10:42:20,137::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getStoragePoolInfo,=20Return=20response:=20{'info':=20{'spm_id':=201,=20=
'master_uuid':=20'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20=
'Default',=20'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,137::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`e84910c4-d6fb-4907-a445-0751d91d715f`::finished:=20{'info':=20=
{'spm_id':=201,=20'master_uuid':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'name':=20'Default',=20=
'version':=20'0',=20'domains':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7:Active,ab686999-f320-4a61-ae07-e99c2=
f858996:Active,9cff8858-9188-42eb-b089-22f89719394d:Active',=20=
'pool_status':=20'connected',=20'isoprefix':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111',=20=
'type':=20'NFS',=20'master_ver':=201,=20'lver':=200},=20'dominfo':=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'status':=20=
'Active',=20'diskfree':=20'177508712448',=20'alerts':=20[],=20=
'disktotal':=20'211379027968'},=20=
'9cff8858-9188-42eb-b089-22f89719394d':=20{'status':=20'Active',=20=
'diskfree':=20'177508712448',=20'alerts':=20[],=20'disktotal':=20=
'211379027968'}}}=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,137::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`e84910c4-d6fb-4907-a445-0751d91d715f`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,137::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20=
{'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7':=20<=20ResourceRef=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20isValid:=20'True'=20=
obj:=20'None'>}=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,138::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,138::resourceManager::538::ResourceManager::(releaseResource)=20=
Trying=20to=20release=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=0A=
Thread-2456766::DEBUG::2013-01-08=20=
10:42:20,138::resourceManager::553::ResourceManager::(releaseResource)=20=
Released=20resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20=
(0=20active=20users)=0AThread-2456766::DEBUG::2013-01-08=20=
10:42:20,138::resourceManager::558::ResourceManager::(releaseResource)=20=
Resource=20'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7'=20is=20free,=20=
finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A=
Thread-2456766::DEBUG::2013-01-08=20=
10:42:20,138::resourceManager::565::ResourceManager::(releaseResource)=20=
No=20one=20is=20waiting=20for=20resource=20=
'Storage.bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20Clearing=20records.=0A=
Thread-2456766::DEBUG::2013-01-08=20=
10:42:20,139::task::957::TaskManager.Task::(_decref)=20=
Task=3D`e84910c4-d6fb-4907-a445-0751d91d715f`::ref=200=20aborting=20=
False=0AThread-2456768::DEBUG::2013-01-08=20=
10:42:20,892::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.196]::call=20vmGetStats=20with=20=
('cfb17b98-1476-4fbf-9fab-7c7f48b60adf',)=20{}=0A=
Thread-2456768::DEBUG::2013-01-08=20=
10:42:20,892::BindingXMLRPC::890::vds::(wrapper)=20return=20vmGetStats=20=
with=20{'status':=20{'message':=20'Virtual=20machine=20does=20not=20=
exist',=20'code':=201}}=0AThread-2456769::DEBUG::2013-01-08=20=
10:42:21,294::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.196]::call=20vmMigrationCreate=20with=20({'username':=20=
'Unknown',=20'acpiEnable':=20'true',=20'emulatedMachine':=20'pc',=20=
'afterMigrationStatus':=20'Up',=20'vmId':=20=
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf',=20'transparentHugePages':=20=
'true',=20'displaySecurePort':=20'5905',=20'timeOffset':=20-2,=20=
'cpuType':=20'Nehalem',=20'custom':=20{},=20'pauseCode':=20'NOERR',=20=
'migrationDest':=20'libvirt',=20'smp':=20'1',=20'vmType':=20'kvm',=20=
'spiceSslCipherSuite':=20'DEFAULT',=20'_srcDomXML':=20"<domain=20=
type=3D'kvm'=20id=3D'4'>\n=20=20<name>test004.domainname.ads</name>\n=20=20=
<uuid>cfb17b98-1476-4fbf-9fab-7c7f48b60adf</uuid>\n=20=20<memory=20=
unit=3D'KiB'>1048576</memory>\n=20=20<currentMemory=20=
unit=3D'KiB'>1048576</currentMemory>\n=20=20<vcpu=20=
placement=3D'static'>1</vcpu>\n=20=20<cputune>\n=20=20=20=20=
<shares>1020</shares>\n=20=20</cputune>\n=20=20<sysinfo=20=
type=3D'smbios'>\n=20=20=20=20<system>\n=20=20=20=20=20=20<entry=20=
name=3D'manufacturer'>oVirt</entry>\n=20=20=20=20=20=20<entry=20=
name=3D'product'>oVirt=20Node</entry>\n=20=20=20=20=20=20<entry=20=
name=3D'version'>6-3.el6.centos.9</entry>\n=20=20=20=20=20=20<entry=20=
name=3D'serial'>55414E03-C241-11DF-BBDA-64093408D485_d4:85:64:09:34:08</en=
try>\n=20=20=20=20=20=20<entry=20=
name=3D'uuid'>cfb17b98-1476-4fbf-9fab-7c7f48b60adf</entry>\n=20=20=20=20=
</system>\n=20=20</sysinfo>\n=20=20<os>\n=20=20=20=20<type=20=
arch=3D'x86_64'=20machine=3D'rhel6.3.0'>hvm</type>\n=20=20=20=20<boot=20=
dev=3D'hd'/>\n=20=20=20=20<smbios=20mode=3D'sysinfo'/>\n=20=20</os>\n=20=20=
<features>\n=20=20=20=20<acpi/>\n=20=20</features>\n=20=20<cpu=20=
mode=3D'custom'=20match=3D'exact'>\n=20=20=20=20<model=20=
fallback=3D'allow'>Nehalem</model>\n=20=20=20=20<topology=20sockets=3D'1'=20=
cores=3D'1'=20threads=3D'1'/>\n=20=20</cpu>\n=20=20<clock=20=
offset=3D'variable'=20adjustment=3D'-2'>\n=20=20=20=20<timer=20=
name=3D'rtc'=20tickpolicy=3D'catchup'/>\n=20=20</clock>\n=20=20=
<on_poweroff>destroy</on_poweroff>\n=20=20=
<on_reboot>restart</on_reboot>\n=20=20<on_crash>destroy</on_crash>\n=20=20=
<devices>\n=20=20=20=20<emulator>/usr/libexec/qemu-kvm</emulator>\n=20=20=
=20=20<disk=20type=3D'file'=20device=3D'cdrom'>\n=20=20=20=20=20=20=
<driver=20name=3D'qemu'=20type=3D'raw'/>\n=20=20=20=20=20=20<source=20=
file=3D'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f3=
20-4a61-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111/cobb=
ler-base.iso'=20startupPolicy=3D'optional'/>\n=20=20=20=20=20=20<target=20=
dev=3D'hdc'=20bus=3D'ide'/>\n=20=20=20=20=20=20<readonly/>\n=20=20=20=20=20=
=20<serial></serial>\n=20=20=20=20=20=20<alias=20name=3D'ide0-1-0'/>\n=20=
=20=20=20=20=20<address=20type=3D'drive'=20controller=3D'0'=20bus=3D'1'=20=
target=3D'0'=20unit=3D'0'/>\n=20=20=20=20</disk>\n=20=20=20=20<disk=20=
type=3D'file'=20device=3D'disk'=20snapshot=3D'no'>\n=20=20=20=20=20=20=
<driver=20name=3D'qemu'=20type=3D'raw'=20cache=3D'none'=20=
error_policy=3D'stop'=20io=3D'threads'/>\n=20=20=20=20=20=20<source=20=
file=3D'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9f=
a3-4896-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e=
7b27-cdbb-4dc7-ba7b-4285719615d4'/>\n=20=20=20=20=20=20<target=20=
dev=3D'vda'=20bus=3D'virtio'/>\n=20=20=20=20=20=20=
<serial>12a6472f-9ab9-436a-8508-b6721cb2b227</serial>\n=20=20=20=20=20=20=
<alias=20name=3D'virtio-disk0'/>\n=20=20=20=20=20=20<address=20=
type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20slot=3D'0x05'=20=
function=3D'0x0'/>\n=20=20=20=20</disk>\n=20=20=20=20<controller=20=
type=3D'usb'=20index=3D'0'>\n=20=20=20=20=20=20<alias=20name=3D'usb0'/>\n=20=
=20=20=20=20=20<address=20type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20=
slot=3D'0x01'=20function=3D'0x2'/>\n=20=20=20=20</controller>\n=20=20=20=20=
<controller=20type=3D'ide'=20index=3D'0'>\n=20=20=20=20=20=20<alias=20=
name=3D'ide0'/>\n=20=20=20=20=20=20<address=20type=3D'pci'=20=
domain=3D'0x0000'=20bus=3D'0x00'=20slot=3D'0x01'=20function=3D'0x1'/>\n=20=
=20=20=20</controller>\n=20=20=20=20<controller=20type=3D'virtio-serial'=20=
index=3D'0'>\n=20=20=20=20=20=20<alias=20name=3D'virtio-serial0'/>\n=20=20=
=20=20=20=20<address=20type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20=
slot=3D'0x04'=20function=3D'0x0'/>\n=20=20=20=20</controller>\n=20=20=20=20=
<interface=20type=3D'bridge'>\n=20=20=20=20=20=20<mac=20=
address=3D'00:1a:4a:c0:2a:05'/>\n=20=20=20=20=20=20<source=20=
bridge=3D'ovirtmgmt'/>\n=20=20=20=20=20=20<target=20dev=3D'vnet2'/>\n=20=20=
=20=20=20=20<model=20type=3D'virtio'/>\n=20=20=20=20=20=20<alias=20=
name=3D'net0'/>\n=20=20=20=20=20=20<address=20type=3D'pci'=20=
domain=3D'0x0000'=20bus=3D'0x00'=20slot=3D'0x03'=20function=3D'0x0'/>\n=20=
=20=20=20</interface>\n=20=20=20=20<console=20type=3D'pty'=20=
tty=3D'/dev/pts/2'>\n=20=20=20=20=20=20<source=20path=3D'/dev/pts/2'/>\n=20=
=20=20=20=20=20<target=20type=3D'virtio'=20port=3D'0'/>\n=20=20=20=20=20=20=
<alias=20name=3D'console0'/>\n=20=20=20=20</console>\n=20=20=20=20=
<channel=20type=3D'unix'>\n=20=20=20=20=20=20<source=20mode=3D'bind'=20=
path=3D'/var/lib/libvirt/qemu/channels/test004.domainname.ads.com.redhat.r=
hevm.vdsm'/>\n=20=20=20=20=20=20<target=20type=3D'virtio'=20=
name=3D'com.redhat.rhevm.vdsm'/>\n=20=20=20=20=20=20<alias=20=
name=3D'channel0'/>\n=20=20=20=20=20=20<address=20type=3D'virtio-serial'=20=
controller=3D'0'=20bus=3D'0'=20port=3D'1'/>\n=20=20=20=20</channel>\n=20=20=
=20=20<channel=20type=3D'unix'>\n=20=20=20=20=20=20<source=20mode=3D'bind'=
=20=
path=3D'/var/lib/libvirt/qemu/channels/test004.domainname.ads.org.qemu.gue=
st_agent.0'/>\n=20=20=20=20=20=20<target=20type=3D'virtio'=20=
name=3D'org.qemu.guest_agent.0'/>\n=20=20=20=20=20=20<alias=20=
name=3D'channel1'/>\n=20=20=20=20=20=20<address=20type=3D'virtio-serial'=20=
controller=3D'0'=20bus=3D'0'=20port=3D'2'/>\n=20=20=20=20</channel>\n=20=20=
=20=20<channel=20type=3D'spicevmc'>\n=20=20=20=20=20=20<target=20=
type=3D'virtio'=20name=3D'com.redhat.spice.0'/>\n=20=20=20=20=20=20=
<alias=20name=3D'channel2'/>\n=20=20=20=20=20=20<address=20=
type=3D'virtio-serial'=20controller=3D'0'=20bus=3D'0'=20port=3D'3'/>\n=20=
=20=20=20</channel>\n=20=20=20=20<input=20type=3D'mouse'=20bus=3D'ps2'/>\n=
=20=20=20=20<graphics=20type=3D'spice'=20port=3D'5904'=20tlsPort=3D'5905'=20=
autoport=3D'yes'=20keymap=3D'en-us'=20=
passwdValidTo=3D'2012-12-19T15:52:56'=20connected=3D'disconnect'>\n=20=20=
=20=20=20=20<listen=20type=3D'network'=20address=3D'10.192.42.196'=20=
network=3D'vdsm-ovirtmgmt'/>\n=20=20=20=20=20=20<channel=20name=3D'main'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'display'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'inputs'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'cursor'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'playback'=20=
mode=3D'secure'/>\n=20=20=20=20=20=20<channel=20name=3D'record'=20=
mode=3D'secure'/>\n=20=20=20=20</graphics>\n=20=20=20=20<video>\n=20=20=20=
=20=20=20<model=20type=3D'qxl'=20vram=3D'65536'=20heads=3D'1'/>\n=20=20=20=
=20=20=20<alias=20name=3D'video0'/>\n=20=20=20=20=20=20<address=20=
type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20slot=3D'0x02'=20=
function=3D'0x0'/>\n=20=20=20=20</video>\n=20=20=20=20<memballoon=20=
model=3D'virtio'>\n=20=20=20=20=20=20<alias=20name=3D'balloon0'/>\n=20=20=
=20=20=20=20<address=20type=3D'pci'=20domain=3D'0x0000'=20bus=3D'0x00'=20=
slot=3D'0x06'=20function=3D'0x0'/>\n=20=20=20=20</memballoon>\n=20=20=
</devices>\n=20=20<seclabel=20type=3D'none'/>\n</domain>\n",=20=
'memSize':=201024,=20'elapsedTimeOffset':=201707876.9180860519,=20=
'vmName':=20'test004.domainname.ads',=20'nice':=20'0',=20'status':=20=
'Up',=20'clientIp':=20'',=20'displayIp':=20'10.192.42.196',=20=
'displayPort':=20'5904',=20'smpCoresPerSocket':=20'1',=20=
'spiceSecureChannels':=20=
'smain,sinputs,scursor,splayback,srecord,sdisplay',=20'nicModel':=20=
'rtl8139,pv',=20'keyboardLayout':=20'en-us',=20'kvmEnable':=20'true',=20=
'pitReinjection':=20'false',=20'displayNetwork':=20'ovirtmgmt',=20=
'devices':=20[{'specParams':=20{'vram':=20'65536'},=20'alias':=20=
'video0',=20'deviceId':=20'0f10b02a-f6bc-432d-bc49-478facf49730',=20=
'address':=20{'slot':=20'0x02',=20'bus':=20'0x00',=20'domain':=20=
'0x0000',=20'type':=20'pci',=20'function':=20'0x0'},=20'device':=20=
'qxl',=20'type':=20'video'},=20{'nicModel':=20'pv',=20'macAddr':=20=
'00:1a:4a:c0:2a:05',=20'network':=20'ovirtmgmt',=20'alias':=20'net0',=20=
'specParams':=20{},=20'deviceId':=20=
'376d1987-d374-486d-8a62-d48ab0a47eb1',=20'address':=20{'slot':=20=
'0x03',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20=
'function':=20'0x0'},=20'device':=20'bridge',=20'type':=20'interface',=20=
'name':=20'vnet2'},=20{'target':=201048576,=20'specParams':=20{'model':=20=
'virtio'},=20'alias':=20'balloon0',=20'deviceId':=20=
'72aaa60a-34e5-41e1-80ea-d9b1c3a1b4e2',=20'address':=20{'slot':=20=
'0x06',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20=
'function':=20'0x0'},=20'device':=20'memballoon',=20'type':=20=
'balloon'},=20{'index':=20'2',=20'iface':=20'ide',=20'name':=20'hdc',=20=
'alias':=20'ide0-1-0',=20'shared':=20'false',=20'specParams':=20{'path':=20=
'cobbler-base.iso'},=20'readonly':=20'True',=20'deviceId':=20=
'58cff440-2f4d-4bbe-94d9-d7c12df85c4d',=20'address':=20{'bus':=20'1',=20=
'controller':=20'0',=20'type':=20'drive',=20'target':=20'0',=20'unit':=20=
'0'},=20'device':=20'cdrom',=20'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111/cobbler-bas=
e.iso',=20'type':=20'disk'},=20{'poolID':=20=
'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20'index':=200,=20'iface':=20=
'virtio',=20'apparentsize':=20'21474836480',=20'alias':=20=
'virtio-disk0',=20'imageID':=20'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
'readonly':=20'False',=20'shared':=20'false',=20'truesize':=20'0',=20=
'type':=20'disk',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'reqsize':=20'0',=20'format':=20=
'raw',=20'deviceId':=20'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
'address':=20{'slot':=20'0x05',=20'bus':=20'0x00',=20'domain':=20=
'0x0000',=20'type':=20'pci',=20'function':=20'0x0'},=20'device':=20=
'disk',=20'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'propagateErrors':=20'off',=20'optional':=20=
'false',=20'name':=20'vda',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'specParams':=20{},=20=
'volumeChain':=20[{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'}]},=20{'device':=20'usb',=20=
'alias':=20'usb0',=20'type':=20'controller',=20'address':=20{'slot':=20=
'0x01',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20=
'function':=20'0x2'}},=20{'device':=20'ide',=20'alias':=20'ide0',=20=
'type':=20'controller',=20'address':=20{'slot':=20'0x01',=20'bus':=20=
'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20'function':=20=
'0x1'}},=20{'device':=20'virtio-serial',=20'alias':=20'virtio-serial0',=20=
'type':=20'controller',=20'address':=20{'slot':=20'0x04',=20'bus':=20=
'0x00',=20'domain':=20'0x0000',=20'type':=20'pci',=20'function':=20=
'0x0'}},=20{'device':=20'unix',=20'alias':=20'channel0',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'1'}},=20{'device':=20'unix',=20=
'alias':=20'channel1',=20'type':=20'channel',=20'address':=20{'bus':=20=
'0',=20'controller':=20'0',=20'type':=20'virtio-serial',=20'port':=20=
'2'}},=20{'device':=20'spicevmc',=20'alias':=20'channel2',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'3'}}],=20'guestIPs':=20'',=20=
'display':=20'qxl'},)=20{}=0AThread-2456769::DEBUG::2013-01-08=20=
10:42:21,294::API::467::vds::(migrationCreate)=20Migration=20create=0A=
Thread-2456769::INFO::2013-01-08=20=
10:42:21,329::clientIF::331::vds::(createVm)=20vmContainerLock=20=
acquired=20by=20vm=20cfb17b98-1476-4fbf-9fab-7c7f48b60adf=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,334::vm::590::vm.Vm::(_startUnderlyingVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Start=0A=
Thread-2456769::DEBUG::2013-01-08=20=
10:42:21,335::clientIF::345::vds::(createVm)=20Total=20desktops=20after=20=
creation=20of=20cfb17b98-1476-4fbf-9fab-7c7f48b60adf=20is=202=0A=
Thread-2456769::DEBUG::2013-01-08=20=
10:42:21,335::libvirtvm::2611::vm.Vm::(waitForMigrationDestinationPrepare)=
=20vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration=20=
destination:=20waiting=20for=20VM=20creation=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,335::vm::594::vm.Vm::(_startUnderlyingVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::_ongoingCreations=20=
acquired=0AThread-2456770::INFO::2013-01-08=20=
10:42:21,335::libvirtvm::1356::vm.Vm::(_run)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::VM=20wrapper=20has=20=
started=0AThread-2456769::DEBUG::2013-01-08=20=
10:42:21,336::libvirtvm::2617::vm.Vm::(waitForMigrationDestinationPrepare)=
=20vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration=20=
destination:=20waiting=2042s=20for=20path=20preparation=0A=
Thread-2456770::WARNING::2013-01-08=20=
10:42:21,336::vm::416::vm.Vm::(getConfDevices)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Unknown=20type=20found,=20=
device:=20'{'device':=20'unix',=20'alias':=20'channel0',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'1'}}'=20found=0A=
Thread-2456770::WARNING::2013-01-08=20=
10:42:21,336::vm::416::vm.Vm::(getConfDevices)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Unknown=20type=20found,=20=
device:=20'{'device':=20'unix',=20'alias':=20'channel1',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'2'}}'=20found=0A=
Thread-2456770::WARNING::2013-01-08=20=
10:42:21,336::vm::416::vm.Vm::(getConfDevices)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Unknown=20type=20found,=20=
device:=20'{'device':=20'spicevmc',=20'alias':=20'channel2',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'3'}}'=20found=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,337::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`6f77554d-92e5-4ea2-89e4-3a594a4bbc0f`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2456770::INFO::2013-01-08=20=
10:42:21,337::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize(sdUUID=3D'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20=
spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
imgUUID=3D'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
volUUID=3D'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20options=3DNone)=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,339::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20732e7b27-cdbb-4dc7-ba7b-4285719615d4=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,342::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20732e7b27-cdbb-4dc7-ba7b-4285719615d4=0A=
Thread-2456770::INFO::2013-01-08=20=
10:42:21,343::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize,=20Return=20response:=20{'truesize':=20'2936401920',=20=
'apparentsize':=20'21474836480'}=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,343::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`6f77554d-92e5-4ea2-89e4-3a594a4bbc0f`::finished:=20{'truesize':=20=
'2936401920',=20'apparentsize':=20'21474836480'}=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,344::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`6f77554d-92e5-4ea2-89e4-3a594a4bbc0f`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,344::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,344::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,344::task::957::TaskManager.Task::(_decref)=20=
Task=3D`6f77554d-92e5-4ea2-89e4-3a594a4bbc0f`::ref=200=20aborting=20=
False=0AThread-2456770::INFO::2013-01-08=20=
10:42:21,344::clientIF::313::vds::(prepareVolumePath)=20prepared=20=
volume=20path:=20=
/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61-=
ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111/cobbler-base=
.iso=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,345::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`023694dd-13d1-4507-8a25-9997e00a0067`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2456770::INFO::2013-01-08=20=
10:42:21,345::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
prepareImage(sdUUID=3D'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20=
spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
imgUUID=3D'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
volUUID=3D'732e7b27-cdbb-4dc7-ba7b-4285719615d4')=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,345::resourceManager::175::ResourceManager.Request::(__init__)=20=
ResName=3D`Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7`ReqID=3D`dc05f7b7-=
01b4-41e6-8dfc-5879d8a45e1c`::Request=20was=20made=20in=20=
'/usr/share/vdsm/storage/resourceManager.py'=20line=20'174'=20at=20=
'__init__'=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,345::resourceManager::486::ResourceManager::(registerResource)=20=
Trying=20to=20register=20resource=20=
'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=20for=20lock=20type=20=
'shared'=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,346::resourceManager::528::ResourceManager::(registerResource)=20=
Resource=20'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=20is=20free.=20=
Now=20locking=20as=20'shared'=20(1=20active=20user)=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,346::resourceManager::212::ResourceManager.Request::(grant)=20=
ResName=3D`Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7`ReqID=3D`dc05f7b7-=
01b4-41e6-8dfc-5879d8a45e1c`::Granted=20request=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,346::task::794::TaskManager.Task::(resourceAcquired)=20=
Task=3D`023694dd-13d1-4507-8a25-9997e00a0067`::_resourcesAcquired:=20=
Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7=20(shared)=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,346::task::957::TaskManager.Task::(_decref)=20=
Task=3D`023694dd-13d1-4507-8a25-9997e00a0067`::ref=201=20aborting=20=
False=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,347::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20732e7b27-cdbb-4dc7-ba7b-4285719615d4=0A=
Thread-2456770::INFO::2013-01-08=20=
10:42:21,368::image::322::Storage.Image::(getChain)=20=
sdUUID=3D2a1939bd-9fa3-4896-b8a9-46234172aae7=20=
imgUUID=3D12a6472f-9ab9-436a-8508-b6721cb2b227=20=
chain=3D[<storage.fileVolume.FileVolume=20object=20at=200x7f7d946190d0>]=20=
=0AThread-2456770::INFO::2013-01-08=20=
10:42:21,370::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
prepareImage,=20Return=20response:=20{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'chain':=20[{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'}]}=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,370::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`023694dd-13d1-4507-8a25-9997e00a0067`::finished:=20{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'chain':=20[{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'}]}=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,370::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`023694dd-13d1-4507-8a25-9997e00a0067`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,370::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20=
{'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7':=20<=20ResourceRef=20=
'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7',=20isValid:=20'True'=20=
obj:=20'None'>}=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,370::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,370::resourceManager::538::ResourceManager::(releaseResource)=20=
Trying=20to=20release=20resource=20=
'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,371::resourceManager::553::ResourceManager::(releaseResource)=20=
Released=20resource=20'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=20=
(0=20active=20users)=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,371::resourceManager::558::ResourceManager::(releaseResource)=20=
Resource=20'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7'=20is=20free,=20=
finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,371::resourceManager::565::ResourceManager::(releaseResource)=20=
No=20one=20is=20waiting=20for=20resource=20=
'Storage.2a1939bd-9fa3-4896-b8a9-46234172aae7',=20Clearing=20records.=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,371::task::957::TaskManager.Task::(_decref)=20=
Task=3D`023694dd-13d1-4507-8a25-9997e00a0067`::ref=200=20aborting=20=
False=0AThread-2456770::INFO::2013-01-08=20=
10:42:21,371::clientIF::313::vds::(prepareVolumePath)=20prepared=20=
volume=20path:=20=
/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896-=
b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cdb=
b-4dc7-ba7b-4285719615d4=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,376::misc::83::Storage.Misc.excCmd::(<lambda>)=20'/usr/bin/sudo=20=
-n=20/sbin/service=20ksmtuned=20retune'=20(cwd=20None)=0A=
Thread-2456769::DEBUG::2013-01-08=20=
10:42:21,376::API::480::vds::(migrationCreate)=20Destination=20VM=20=
creation=20succeeded=0AThread-2456769::DEBUG::2013-01-08=20=
10:42:21,383::BindingXMLRPC::890::vds::(wrapper)=20return=20=
vmMigrationCreate=20with=20{'status':=20{'message':=20'Done',=20'code':=20=
0},=20'migrationPort':=200,=20'params':=20{'status':=20'Migration=20=
Destination',=20'acpiEnable':=20'true',=20'emulatedMachine':=20'pc',=20=
'afterMigrationStatus':=20'Up',=20'pid':=20'0',=20=
'transparentHugePages':=20'true',=20'displaySecurePort':=20'-1',=20=
'timeOffset':=20-2,=20'cpuType':=20'Nehalem',=20'smp':=20'1',=20=
'pauseCode':=20'NOERR',=20'migrationDest':=20'libvirt',=20'custom':=20=
{},=20'vmType':=20'kvm',=20'spiceSslCipherSuite':=20'DEFAULT',=20=
'memSize':=201024,=20'vmName':=20'test004.domainname.ads',=20'nice':=20=
'0',=20'username':=20'Unknown',=20'vmId':=20=
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf',=20'displayIp':=20=
'10.192.42.165',=20'keyboardLayout':=20'en-us',=20'displayPort':=20'-1',=20=
'guestIPs':=20'',=20'spiceSecureChannels':=20=
'smain,sinputs,scursor,splayback,srecord,sdisplay',=20'nicModel':=20=
'rtl8139,pv',=20'smpCoresPerSocket':=20'1',=20'kvmEnable':=20'true',=20=
'pitReinjection':=20'false',=20'displayNetwork':=20'ovirtmgmt',=20=
'devices':=20[{'device':=20'usb',=20'alias':=20'usb0',=20'type':=20=
'controller',=20'address':=20{'slot':=20'0x01',=20'bus':=20'0x00',=20=
'domain':=20'0x0000',=20'type':=20'pci',=20'function':=20'0x2'}},=20=
{'device':=20'ide',=20'alias':=20'ide0',=20'type':=20'controller',=20=
'address':=20{'slot':=20'0x01',=20'bus':=20'0x00',=20'domain':=20=
'0x0000',=20'type':=20'pci',=20'function':=20'0x1'}},=20{'device':=20=
'virtio-serial',=20'alias':=20'virtio-serial0',=20'type':=20=
'controller',=20'address':=20{'slot':=20'0x04',=20'bus':=20'0x00',=20=
'domain':=20'0x0000',=20'type':=20'pci',=20'function':=20'0x0'}},=20=
{'specParams':=20{'vram':=20'65536'},=20'alias':=20'video0',=20=
'deviceId':=20'0f10b02a-f6bc-432d-bc49-478facf49730',=20'address':=20=
{'slot':=20'0x02',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20=
'pci',=20'function':=20'0x0'},=20'device':=20'qxl',=20'type':=20=
'video'},=20{'nicModel':=20'pv',=20'macAddr':=20'00:1a:4a:c0:2a:05',=20=
'network':=20'ovirtmgmt',=20'alias':=20'net0',=20'specParams':=20{},=20=
'deviceId':=20'376d1987-d374-486d-8a62-d48ab0a47eb1',=20'address':=20=
{'slot':=20'0x03',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20=
'pci',=20'function':=20'0x0'},=20'device':=20'bridge',=20'type':=20=
'interface',=20'name':=20'vnet2'},=20{'target':=201048576,=20=
'specParams':=20{'model':=20'virtio'},=20'alias':=20'balloon0',=20=
'deviceId':=20'72aaa60a-34e5-41e1-80ea-d9b1c3a1b4e2',=20'address':=20=
{'slot':=20'0x06',=20'bus':=20'0x00',=20'domain':=20'0x0000',=20'type':=20=
'pci',=20'function':=20'0x0'},=20'device':=20'memballoon',=20'type':=20=
'balloon'},=20{'index':=20'2',=20'iface':=20'ide',=20'name':=20'hdc',=20=
'alias':=20'ide0-1-0',=20'shared':=20'false',=20'specParams':=20{'path':=20=
'cobbler-base.iso'},=20'readonly':=20'True',=20'deviceId':=20=
'58cff440-2f4d-4bbe-94d9-d7c12df85c4d',=20'address':=20{'bus':=20'1',=20=
'controller':=20'0',=20'type':=20'drive',=20'target':=20'0',=20'unit':=20=
'0'},=20'device':=20'cdrom',=20'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/ab686999-f320-4a61=
-ae07-e99c2f858996/images/11111111-1111-1111-1111-111111111111/cobbler-bas=
e.iso',=20'type':=20'disk'},=20{'poolID':=20=
'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20'index':=200,=20'iface':=20=
'virtio',=20'apparentsize':=20'21474836480',=20'alias':=20=
'virtio-disk0',=20'imageID':=20'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
'readonly':=20'False',=20'shared':=20'false',=20'truesize':=20=
'2936401920',=20'type':=20'disk',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'reqsize':=20'0',=20'format':=20=
'raw',=20'deviceId':=20'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
'address':=20{'slot':=20'0x05',=20'bus':=20'0x00',=20'domain':=20=
'0x0000',=20'type':=20'pci',=20'function':=20'0x0'},=20'device':=20=
'disk',=20'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'propagateErrors':=20'off',=20'optional':=20=
'false',=20'name':=20'vda',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'specParams':=20{},=20=
'volumeChain':=20[{'path':=20=
'/rhev/data-center/bb0beebf-edab-41e2-83b8-16bdbbc5dda7/2a1939bd-9fa3-4896=
-b8a9-46234172aae7/images/12a6472f-9ab9-436a-8508-b6721cb2b227/732e7b27-cd=
bb-4dc7-ba7b-4285719615d4',=20'domainID':=20=
'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20'volumeID':=20=
'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'}]},=20{'device':=20'unix',=20=
'alias':=20'channel0',=20'type':=20'channel',=20'address':=20{'bus':=20=
'0',=20'controller':=20'0',=20'type':=20'virtio-serial',=20'port':=20=
'1'}},=20{'device':=20'unix',=20'alias':=20'channel1',=20'type':=20=
'channel',=20'address':=20{'bus':=20'0',=20'controller':=20'0',=20=
'type':=20'virtio-serial',=20'port':=20'2'}},=20{'device':=20'spicevmc',=20=
'alias':=20'channel2',=20'type':=20'channel',=20'address':=20{'bus':=20=
'0',=20'controller':=20'0',=20'type':=20'virtio-serial',=20'port':=20=
'3'}}],=20'clientIp':=20'',=20'display':=20'qxl'}}=0A=
Thread-2456770::DEBUG::2013-01-08=20=
10:42:21,422::misc::83::Storage.Misc.excCmd::(<lambda>)=20SUCCESS:=20=
<err>=20=3D=20'';=20<rc>=20=3D=200=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,423::vm::611::vm.Vm::(_startUnderlyingVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::_ongoingCreations=20=
released=0AThread-2456770::DEBUG::2013-01-08=20=
10:42:21,423::libvirtvm::1669::vm.Vm::(_waitForIncomingMigrationFinish)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Waiting=20300=20seconds=20=
for=20end=20of=20migration=0AThread-2456772::DEBUG::2013-01-08=20=
10:42:22,523::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`16f59db2-fcff-4f03-b964-1ed70965d150`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2456772::INFO::2013-01-08=20=
10:42:22,523::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats(options=3DNone)=0AThread-2456772::INFO::2013-01-08=20=
10:42:22,524::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats,=20Return=20response:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00229406356812',=20'lastCheck':=20'8.0',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00214695930481',=20'lastCheck':=20'6.3',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00227403640747',=20'lastCheck':=20'6.4',=20'code':=200,=20'valid':=20=
True}}=0AThread-2456772::DEBUG::2013-01-08=20=
10:42:22,524::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`16f59db2-fcff-4f03-b964-1ed70965d150`::finished:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00229406356812',=20'lastCheck':=20'8.0',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00214695930481',=20'lastCheck':=20'6.3',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00227403640747',=20'lastCheck':=20'6.4',=20'code':=200,=20'valid':=20=
True}}=0AThread-2456772::DEBUG::2013-01-08=20=
10:42:22,524::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`16f59db2-fcff-4f03-b964-1ed70965d150`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2456772::DEBUG::2013-01-08=20=
10:42:22,524::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2456772::DEBUG::2013-01-08=20=
10:42:22,524::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2456772::DEBUG::2013-01-08=20=
10:42:22,524::task::957::TaskManager.Task::(_decref)=20=
Task=3D`16f59db2-fcff-4f03-b964-1ed70965d150`::ref=200=20aborting=20=
False=0AThread-2456773::DEBUG::2013-01-08=20=
10:42:22,537::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`a08884f6-d634-4d1d-a0ef-f77cd96f0953`::Disk=20vda=20latency=20=
not=20available=0AThread-2456774::DEBUG::2013-01-08=20=
10:42:22,717::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.196]::call=20vmDestroy=20with=20=
('cfb17b98-1476-4fbf-9fab-7c7f48b60adf',)=20{}=0A=
Thread-2456774::INFO::2013-01-08=20=
10:42:22,717::API::308::vds::(destroy)=20vmContainerLock=20acquired=20by=20=
vm=20cfb17b98-1476-4fbf-9fab-7c7f48b60adf=0A=
Thread-2456774::DEBUG::2013-01-08=20=
10:42:22,718::libvirtvm::2209::vm.Vm::(destroy)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::destroy=20Called=0A=
Thread-2456774::INFO::2013-01-08=20=
10:42:22,718::libvirtvm::2160::vm.Vm::(releaseVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Release=20VM=20resources=0A=
Thread-2456774::DEBUG::2013-01-08=20=
10:42:22,718::misc::83::Storage.Misc.excCmd::(<lambda>)=20'/usr/bin/sudo=20=
-n=20/sbin/service=20ksmtuned=20retune'=20(cwd=20None)=0A=
Thread-2456774::DEBUG::2013-01-08=20=
10:42:22,755::misc::83::Storage.Misc.excCmd::(<lambda>)=20SUCCESS:=20=
<err>=20=3D=20'';=20<rc>=20=3D=200=0AThread-2456774::DEBUG::2013-01-08=20=
10:42:22,756::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`19304f16-6634-40f2-aeb5-081cb423eb7d`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-2456774::INFO::2013-01-08=20=
10:42:22,756::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
inappropriateDevices(thiefId=3D'cfb17b98-1476-4fbf-9fab-7c7f48b60adf')=0A=
Thread-2456774::INFO::2013-01-08=20=
10:42:22,769::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
inappropriateDevices,=20Return=20response:=20None=0A=
Thread-2456774::DEBUG::2013-01-08=20=
10:42:22,770::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`19304f16-6634-40f2-aeb5-081cb423eb7d`::finished:=20None=0A=
Thread-2456774::DEBUG::2013-01-08=20=
10:42:22,770::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`19304f16-6634-40f2-aeb5-081cb423eb7d`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-2456774::DEBUG::2013-01-08=20=
10:42:22,770::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-2456774::DEBUG::2013-01-08=20=
10:42:22,770::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-2456774::DEBUG::2013-01-08=20=
10:42:22,770::task::957::TaskManager.Task::(_decref)=20=
Task=3D`19304f16-6634-40f2-aeb5-081cb423eb7d`::ref=200=20aborting=20=
False=0AThread-2456774::DEBUG::2013-01-08=20=
10:42:22,771::libvirtvm::2203::vm.Vm::(deleteVm)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Total=20desktops=20after=20=
destroy=20of=20cfb17b98-1476-4fbf-9fab-7c7f48b60adf=20is=201=0A=
Thread-2456774::DEBUG::2013-01-08=20=
10:42:22,771::BindingXMLRPC::890::vds::(wrapper)=20return=20vmDestroy=20=
with=20{'status':=20{'message':=20'Machine=20destroyed',=20'code':=200}}=0A=
--Apple-Mail=_C82D1F4B-8BD2-4AB4-8D7E-7DAE9D5676F1
Content-Disposition: attachment;
filename=migrate-src.log
Content-Type: application/octet-stream;
name="migrate-src.log"
Content-Transfer-Encoding: quoted-printable
Thread-1484330::DEBUG::2013-01-08=20=
10:40:59,186::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`7417efd1-9122-4c1c-8f64-b2df0bcbc07d`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-1484330::INFO::2013-01-08=20=
10:40:59,186::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats(options=3DNone)=0AThread-1484330::INFO::2013-01-08=20=
10:40:59,186::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats,=20Return=20response:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00235295295715',=20'lastCheck':=20'1.9',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00221991539001',=20'lastCheck':=20'0.8',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00199294090271',=20'lastCheck':=20'0.8',=20'code':=200,=20'valid':=20=
True}}=0AThread-1484330::DEBUG::2013-01-08=20=
10:40:59,186::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`7417efd1-9122-4c1c-8f64-b2df0bcbc07d`::finished:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00235295295715',=20'lastCheck':=20'1.9',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00221991539001',=20'lastCheck':=20'0.8',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00199294090271',=20'lastCheck':=20'0.8',=20'code':=200,=20'valid':=20=
True}}=0AThread-1484330::DEBUG::2013-01-08=20=
10:40:59,186::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`7417efd1-9122-4c1c-8f64-b2df0bcbc07d`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-1484330::DEBUG::2013-01-08=20=
10:40:59,186::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-1484330::DEBUG::2013-01-08=20=
10:40:59,187::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-1484330::DEBUG::2013-01-08=20=
10:40:59,187::task::957::TaskManager.Task::(_decref)=20=
Task=3D`7417efd1-9122-4c1c-8f64-b2df0bcbc07d`::ref=200=20aborting=20=
False=0AThread-1484331::DEBUG::2013-01-08=20=
10:40:59,402::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk=20vda=20latency=20=
not=20available=0AThread-1484331::DEBUG::2013-01-08=20=
10:40:59,402::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`7b8f725b-0a67-46d4-a3cf-db43daad0c42`::Disk=20vda=20latency=20=
not=20available=0AThread-1484331::DEBUG::2013-01-08=20=
10:40:59,402::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`9dc63ce4-0f76-4963-adfe-6f8eb1a44806`::Disk=20vda=20latency=20=
not=20available=0AThread-1484331::DEBUG::2013-01-08=20=
10:40:59,403::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`e8683e88-f3f2-4fe9-80f7-f4888d8e7a13`::Disk=20vda=20latency=20=
not=20available=0AThread-417786::DEBUG::2013-01-08=20=
10:41:00,312::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`966b7fee-f32b-4c1e-914f-b40a8a7ff75b`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-417786::INFO::2013-01-08=20=
10:41:00,312::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize(sdUUID=3D'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20=
spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
imgUUID=3D'12a6472f-9ab9-436a-8508-b6721cb2b227',=20=
volUUID=3D'732e7b27-cdbb-4dc7-ba7b-4285719615d4',=20options=3DNone)=0A=
Thread-417786::DEBUG::2013-01-08=20=
10:41:00,314::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20732e7b27-cdbb-4dc7-ba7b-4285719615d4=0A=
Thread-417786::DEBUG::2013-01-08=20=
10:41:00,317::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=20732e7b27-cdbb-4dc7-ba7b-4285719615d4=0A=
Thread-417786::INFO::2013-01-08=20=
10:41:00,319::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize,=20Return=20response:=20{'truesize':=20'2936401920',=20=
'apparentsize':=20'21474836480'}=0AThread-417786::DEBUG::2013-01-08=20=
10:41:00,319::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`966b7fee-f32b-4c1e-914f-b40a8a7ff75b`::finished:=20{'truesize':=20=
'2936401920',=20'apparentsize':=20'21474836480'}=0A=
Thread-417786::DEBUG::2013-01-08=20=
10:41:00,319::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`966b7fee-f32b-4c1e-914f-b40a8a7ff75b`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-417786::DEBUG::2013-01-08=20=
10:41:00,319::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-417786::DEBUG::2013-01-08=20=
10:41:00,319::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-417786::DEBUG::2013-01-08=20=
10:41:00,320::task::957::TaskManager.Task::(_decref)=20=
Task=3D`966b7fee-f32b-4c1e-914f-b40a8a7ff75b`::ref=200=20aborting=20=
False=0AThread-1284213::DEBUG::2013-01-08=20=
10:41:00,325::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`f9a27440-7e81-4f9a-918b-59db7a0173e9`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-1284213::INFO::2013-01-08=20=
10:41:00,326::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize(sdUUID=3D'2a1939bd-9fa3-4896-b8a9-46234172aae7',=20=
spUUID=3D'bb0beebf-edab-41e2-83b8-16bdbbc5dda7',=20=
imgUUID=3D'8f2e2e18-0f8b-4e35-bdaf-8c853d8fb090',=20=
volUUID=3D'7a569331-46e2-4e53-b8a9-9ef51290125e',=20options=3DNone)=0A=
Thread-1284213::DEBUG::2013-01-08=20=
10:41:00,328::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=207a569331-46e2-4e53-b8a9-9ef51290125e=0A=
Thread-1284213::DEBUG::2013-01-08=20=
10:41:00,331::fileVolume::558::Storage.Volume::(validateVolumePath)=20=
validate=20path=20for=207a569331-46e2-4e53-b8a9-9ef51290125e=0A=
Thread-1284213::INFO::2013-01-08=20=
10:41:00,332::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
getVolumeSize,=20Return=20response:=20{'truesize':=20'10737422336',=20=
'apparentsize':=20'10737418240'}=0AThread-1284213::DEBUG::2013-01-08=20=
10:41:00,332::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`f9a27440-7e81-4f9a-918b-59db7a0173e9`::finished:=20{'truesize':=20=
'10737422336',=20'apparentsize':=20'10737418240'}=0A=
Thread-1284213::DEBUG::2013-01-08=20=
10:41:00,332::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`f9a27440-7e81-4f9a-918b-59db7a0173e9`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-1284213::DEBUG::2013-01-08=20=
10:41:00,332::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-1284213::DEBUG::2013-01-08=20=
10:41:00,332::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-1284213::DEBUG::2013-01-08=20=
10:41:00,333::task::957::TaskManager.Task::(_decref)=20=
Task=3D`f9a27440-7e81-4f9a-918b-59db7a0173e9`::ref=200=20aborting=20=
False=0A=0A=0A=0A=0A=0A=0A=0A=0A=0A=0A=0A=0A=
Thread-1484336::DEBUG::2013-01-08=20=
10:41:07,659::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.207]::call=20vmMigrate=20with=20({'src':=20'10.192.42.196',=20=
'dst':=20'10.192.42.165:54321',=20'vmId':=20=
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf',=20'method':=20'online'},)=20{}=20=
flowID=20[13b25d64]=0AThread-1484336::DEBUG::2013-01-08=20=
10:41:07,659::API::432::vds::(migrate)=20{'src':=20'10.192.42.196',=20=
'dst':=20'10.192.42.165:54321',=20'vmId':=20=
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf',=20'method':=20'online'}=0A=
Thread-1484337::DEBUG::2013-01-08=20=
10:41:07,660::vm::125::vm.Vm::(_setupVdsConnection)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Destination=20server=20=
is:=2010.192.42.165:54321=0AThread-1484336::DEBUG::2013-01-08=20=
10:41:07,660::BindingXMLRPC::890::vds::(wrapper)=20return=20vmMigrate=20=
with=20{'status':=20{'message':=20'Migration=20process=20starting',=20=
'code':=200}}=0AThread-1484337::DEBUG::2013-01-08=20=
10:41:07,660::vm::127::vm.Vm::(_setupVdsConnection)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Initiating=20connection=20=
with=20destination=0AThread-1484337::DEBUG::2013-01-08=20=
10:41:07,752::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk=20vda=20latency=20=
not=20available=0AThread-1484337::DEBUG::2013-01-08=20=
10:41:07,835::vm::173::vm.Vm::(_prepareGuest)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration=20Process=20=
begins=0AThread-1484337::DEBUG::2013-01-08=20=
10:41:07,927::vm::237::vm.Vm::(run)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration=20semaphore=20=
acquired=0AThread-1484337::DEBUG::2013-01-08=20=
10:41:08,251::libvirtvm::449::vm.Vm::(_startUnderlyingMigration)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::starting=20migration=20to=20=
qemu+tls://10.192.42.165/system=0AThread-1484338::DEBUG::2013-01-08=20=
10:41:08,251::libvirtvm::335::vm.Vm::(run)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration=20downtime=20=
thread=20started=0AThread-1484339::DEBUG::2013-01-08=20=
10:41:08,252::libvirtvm::371::vm.Vm::(run)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::starting=20migration=20=
monitor=20thread=0AThread-1484337::DEBUG::2013-01-08=20=
10:41:09,521::libvirtvm::350::vm.Vm::(cancel)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::canceling=20migration=20=
downtime=20thread=0AThread-1484337::DEBUG::2013-01-08=20=
10:41:09,521::libvirtvm::409::vm.Vm::(stop)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::stopping=20migration=20=
monitor=20thread=0AThread-1484338::DEBUG::2013-01-08=20=
10:41:09,522::libvirtvm::347::vm.Vm::(run)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration=20downtime=20=
thread=20exiting=0AThread-1484337::ERROR::2013-01-08=20=
10:41:09,522::vm::179::vm.Vm::(_recover)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::internal=20error=20=
Process=20exited=20while=20reading=20console=20log=20output:=20=0A=
Thread-1484340::DEBUG::2013-01-08=20=
10:41:09,544::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`bfebf940-d2a3-4b6c-948b-cac951a686bf`::moving=20from=20state=20=
init=20->=20state=20preparing=0AThread-1484340::INFO::2013-01-08=20=
10:41:09,544::logUtils::37::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats(options=3DNone)=0AThread-1484340::INFO::2013-01-08=20=
10:41:09,544::logUtils::39::dispatcher::(wrapper)=20Run=20and=20protect:=20=
repoStats,=20Return=20response:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00229001045227',=20'lastCheck':=20'2.2',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00204110145569',=20'lastCheck':=20'1.1',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00174999237061',=20'lastCheck':=20'1.1',=20'code':=200,=20'valid':=20=
True}}=0AThread-1484340::DEBUG::2013-01-08=20=
10:41:09,544::task::1151::TaskManager.Task::(prepare)=20=
Task=3D`bfebf940-d2a3-4b6c-948b-cac951a686bf`::finished:=20=
{'2a1939bd-9fa3-4896-b8a9-46234172aae7':=20{'delay':=20=
'0.00229001045227',=20'lastCheck':=20'2.2',=20'code':=200,=20'valid':=20=
True},=20'ab686999-f320-4a61-ae07-e99c2f858996':=20{'delay':=20=
'0.00204110145569',=20'lastCheck':=20'1.1',=20'code':=200,=20'valid':=20=
True},=20'9cff8858-9188-42eb-b089-22f89719394d':=20{'delay':=20=
'0.00174999237061',=20'lastCheck':=20'1.1',=20'code':=200,=20'valid':=20=
True}}=0AThread-1484340::DEBUG::2013-01-08=20=
10:41:09,544::task::568::TaskManager.Task::(_updateState)=20=
Task=3D`bfebf940-d2a3-4b6c-948b-cac951a686bf`::moving=20from=20state=20=
preparing=20->=20state=20finished=0AThread-1484340::DEBUG::2013-01-08=20=
10:41:09,545::resourceManager::809::ResourceManager.Owner::(releaseAll)=20=
Owner.releaseAll=20requests=20{}=20resources=20{}=0A=
Thread-1484340::DEBUG::2013-01-08=20=
10:41:09,545::resourceManager::844::ResourceManager.Owner::(cancelAll)=20=
Owner.cancelAll=20requests=20{}=0AThread-1484340::DEBUG::2013-01-08=20=
10:41:09,545::task::957::TaskManager.Task::(_decref)=20=
Task=3D`bfebf940-d2a3-4b6c-948b-cac951a686bf`::ref=200=20aborting=20=
False=0AThread-1484341::DEBUG::2013-01-08=20=
10:41:09,558::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk=20vda=20latency=20=
not=20available=0AThread-1484341::DEBUG::2013-01-08=20=
10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`7b8f725b-0a67-46d4-a3cf-db43daad0c42`::Disk=20vda=20latency=20=
not=20available=0AThread-1484341::DEBUG::2013-01-08=20=
10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`9dc63ce4-0f76-4963-adfe-6f8eb1a44806`::Disk=20vda=20latency=20=
not=20available=0AThread-1484341::DEBUG::2013-01-08=20=
10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`e8683e88-f3f2-4fe9-80f7-f4888d8e7a13`::Disk=20vda=20latency=20=
not=20available=0AThread-1484337::ERROR::2013-01-08=20=
10:41:09,754::vm::258::vm.Vm::(run)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Failed=20to=20migrate=0A=
Traceback=20(most=20recent=20call=20last):=0A=20=20File=20=
"/usr/share/vdsm/vm.py",=20line=20245,=20in=20run=0A=20=20=20=20=
self._startUnderlyingMigration()=0A=20=20File=20=
"/usr/share/vdsm/libvirtvm.py",=20line=20474,=20in=20=
_startUnderlyingMigration=0A=20=20=20=20None,=20maxBandwidth)=0A=20=20=
File=20"/usr/share/vdsm/libvirtvm.py",=20line=20510,=20in=20f=0A=20=20=20=
=20ret=20=3D=20attr(*args,=20**kwargs)=0A=20=20File=20=
"/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py",=20line=20=
83,=20in=20wrapper=0A=20=20=20=20ret=20=3D=20f(*args,=20**kwargs)=0A=20=20=
File=20"/usr/lib64/python2.6/site-packages/libvirt.py",=20line=201103,=20=
in=20migrateToURI2=0A=20=20=20=20if=20ret=20=3D=3D=20-1:=20raise=20=
libvirtError=20('virDomainMigrateToURI2()=20failed',=20dom=3Dself)=0A=
libvirtError:=20internal=20error=20Process=20exited=20while=20reading=20=
console=20log=20output:=20=0AThread-1484343::DEBUG::2013-01-08=20=
10:41:11,654::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.207]::call=20vmGetStats=20with=20=
('cfb17b98-1476-4fbf-9fab-7c7f48b60adf',)=20{}=0A=
Thread-1484343::DEBUG::2013-01-08=20=
10:41:11,654::libvirtvm::278::vm.Vm::(_getDiskLatency)=20=
vmId=3D`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk=20vda=20latency=20=
not=20available=0AThread-1484343::DEBUG::2013-01-08=20=
10:41:11,655::BindingXMLRPC::890::vds::(wrapper)=20return=20vmGetStats=20=
with=20{'status':=20{'message':=20'Done',=20'code':=200},=20'statsList':=20=
[{'status':=20'Up',=20'username':=20'Unknown',=20'memUsage':=20'0',=20=
'acpiEnable':=20'true',=20'pid':=20'5780',=20'displayIp':=20=
'10.192.42.196',=20'displayPort':=20u'5904',=20'session':=20'Unknown',=20=
'displaySecurePort':=20u'5905',=20'timeOffset':=20-2L,=20'hash':=20=
'-7242028114076316120',=20'balloonInfo':=20{'balloon_max':=201048576,=20=
'balloon_cur':=201048576},=20'pauseCode':=20'NOERR',=20'clientIp':=20'',=20=
'kvmEnable':=20'true',=20'network':=20{u'vnet2':=20{'macAddr':=20=
'00:1a:4a:c0:2a:05',=20'rxDropped':=20'0',=20'rxErrors':=20'0',=20=
'txDropped':=20'0',=20'txRate':=20'0.0',=20'rxRate':=20'0.0',=20=
'txErrors':=20'0',=20'state':=20'unknown',=20'speed':=20'1000',=20=
'name':=20u'vnet2'}},=20'vmId':=20=
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf',=20'displayType':=20'qxl',=20=
'cpuUser':=20'0.49',=20'disks':=20{u'vda':=20{'readRate':=20'0.00',=20=
'truesize':=20'2936401920',=20'apparentsize':=20'21474836480',=20=
'writeRate':=20'1273.87',=20'imageID':=20=
'12a6472f-9ab9-436a-8508-b6721cb2b227'},=20u'hdc':=20{'readLatency':=20=
'0',=20'apparentsize':=20'0',=20'writeLatency':=20'0',=20'flushLatency':=20=
'0',=20'readRate':=20'0.00',=20'truesize':=20'0',=20'writeRate':=20=
'0.00'}},=20'monitorResponse':=20'0',=20'statsAge':=20'0.36',=20=
'elapsedTime':=20'1707880',=20'vmType':=20'kvm',=20'cpuSys':=20'0.40',=20=
'appsList':=20[],=20'guestIPs':=20''}]}=0A=
Thread-1484344::DEBUG::2013-01-08=20=
10:41:11,679::BindingXMLRPC::883::vds::(wrapper)=20client=20=
[10.192.42.207]::call=20vmGetMigrationStatus=20with=20=
('cfb17b98-1476-4fbf-9fab-7c7f48b60adf',)=20{}=0A=
Thread-1484344::DEBUG::2013-01-08=20=
10:41:11,679::BindingXMLRPC::890::vds::(wrapper)=20return=20=
vmGetMigrationStatus=20with=20{'status':=20{'message':=20'Fatal=20error=20=
during=20migration',=20'code':=2012}}=0AVM=20Channels=20=
Listener::DEBUG::2013-01-08=20=
10:41:12,057::vmChannels::60::vds::(_handle_timeouts)=20Timeout=20on=20=
fileno=2018.=0A=
--Apple-Mail=_C82D1F4B-8BD2-4AB4-8D7E-7DAE9D5676F1
Content-Transfer-Encoding: 7bit
Content-Type: text/plain;
charset=iso-8859-1
log from both sides.
see attached
--Apple-Mail=_C82D1F4B-8BD2-4AB4-8D7E-7DAE9D5676F1--
1:35 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
odd,
migration seem to be successful on destination server, but source reports a problem:
Thread-1484336::DEBUG::2013-01-08 10:41:07,659::BindingXMLRPC::883::vds::(wrapper) client
[10.192.42.207]::call vmMigrate with ({'src': '10.192.42.196',
'dst': '10.192.42.165:54321', 'vmId': 'cfb17b98-1476-4fbf-9f
Thread-1484336::DEBUG::2013-01-08 10:41:07,659::API::432::vds::(migrate) {'src':
'10.192.42.196', 'dst': '10.192.42.165:54321', 'vmId':
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf', 'method': 'online'}
Thread-1484337::DEBUG::2013-01-08 10:41:07,660::vm::125::vm.Vm::(_setupVdsConnection)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Destination server is: 10.192.42.165:54321
Thread-1484336::DEBUG::2013-01-08 10:41:07,660::BindingXMLRPC::890::vds::(wrapper) return
vmMigrate with {'status': {'message': 'Migration process
starting', 'code': 0}}
Thread-1484337::DEBUG::2013-01-08 10:41:07,660::vm::127::vm.Vm::(_setupVdsConnection)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Initiating connection with destination
Thread-1484337::DEBUG::2013-01-08 10:41:07,752::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk vda latency not available
Thread-1484337::DEBUG::2013-01-08 10:41:07,835::vm::173::vm.Vm::(_prepareGuest)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration Process begins
Thread-1484337::DEBUG::2013-01-08 10:41:07,927::vm::237::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration semaphore acquired
Thread-1484337::DEBUG::2013-01-08
10:41:08,251::libvirtvm::449::vm.Vm::(_startUnderlyingMigration)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::starting migration to
qemu+tls://10.192.42.165/system
Thread-1484338::DEBUG::2013-01-08 10:41:08,251::libvirtvm::335::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration downtime thread started
Thread-1484339::DEBUG::2013-01-08 10:41:08,252::libvirtvm::371::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::starting migration monitor thread
Thread-1484337::DEBUG::2013-01-08 10:41:09,521::libvirtvm::350::vm.Vm::(cancel)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::canceling migration downtime thread
Thread-1484337::DEBUG::2013-01-08 10:41:09,521::libvirtvm::409::vm.Vm::(stop)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::stopping migration monitor thread
Thread-1484338::DEBUG::2013-01-08 10:41:09,522::libvirtvm::347::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration downtime thread exiting
Thread-1484337::ERROR::2013-01-08 10:41:09,522::vm::179::vm.Vm::(_recover)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::internal error Process exited while reading
console log output:
Thread-1484340::DEBUG::2013-01-08
10:41:09,544::task::568::TaskManager.Task::(_updateState)
Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::moving from state init -> state preparing
Thread-1484340::INFO::2013-01-08 10:41:09,544::logUtils::37::dispatcher::(wrapper) Run and
protect: repoStats(options=None)
Thread-1484340::INFO::2013-01-08 10:41:09,544::logUtils::39::dispatcher::(wrapper) Run and
protect: repoStats, Return response: {'2a1939bd-9fa3-4896-b8a9-46234172aae7':
{'delay': '0.00229001045227', 'lastCheck': '
Thread-1484340::DEBUG::2013-01-08 10:41:09,544::task::1151::TaskManager.Task::(prepare)
Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::finished:
{'2a1939bd-9fa3-4896-b8a9-46234172aae7': {'delay':
'0.00229001045227',
Thread-1484340::DEBUG::2013-01-08
10:41:09,544::task::568::TaskManager.Task::(_updateState)
Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::moving from state preparing -> state
finished
Thread-1484340::DEBUG::2013-01-08
10:41:09,545::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-1484340::DEBUG::2013-01-08
10:41:09,545::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-1484340::DEBUG::2013-01-08 10:41:09,545::task::957::TaskManager.Task::(_decref)
Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::ref 0 aborting False
Thread-1484341::DEBUG::2013-01-08 10:41:09,558::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk vda latency not available
Thread-1484341::DEBUG::2013-01-08 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`7b8f725b-0a67-46d4-a3cf-db43daad0c42`::Disk vda latency not available
Thread-1484341::DEBUG::2013-01-08 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`9dc63ce4-0f76-4963-adfe-6f8eb1a44806`::Disk vda latency not available
Thread-1484341::DEBUG::2013-01-08 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`e8683e88-f3f2-4fe9-80f7-f4888d8e7a13`::Disk vda latency not available
Thread-1484337::ERROR::2013-01-08 10:41:09,754::vm::258::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Failed to migrate
Traceback (most recent call last):
File "/usr/share/vdsm/vm.py", line 245, in run
self._startUnderlyingMigration()
File "/usr/share/vdsm/libvirtvm.py", line 474, in _startUnderlyingMigration
None, maxBandwidth)
File "/usr/share/vdsm/libvirtvm.py", line 510, in f
ret = attr(*args, **kwargs)
File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 83,
in wrapper
ret = f(*args, **kwargs)
File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1103, in
migrateToURI2
if ret == -1: raise libvirtError ('virDomainMigrateToURI2() failed',
dom=self)
libvirtError: internal error Process exited while reading console log output:
any chance you attach libvirtd.log and qemu log (/var/log/libvirt/qemu/{}.log?
Danken - any insights?
----- Original Message -----
From: "Tom Brown" <tom(a)ng23.net>
To: "Roy Golan" <rgolan(a)redhat.com>
Cc: "Haim Ateya" <hateya(a)redhat.com>, users(a)ovirt.org
Sent: Tuesday, January 8, 2013 11:50:26 AM
Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
> can you attach the same snip from the src VDSM 10.192.42.196 as
> well?
The log is pretty chatty therefore i did another migration attempt
and snipd'd the new
log from both sides.
see attached
4:06 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
> libvirtError: internal error Process exited while reading console
log outpu
could this be related to selinux? can you try disabling it and see if migration succeeds?
It was indeed the case! my src node was set to disabled and my destination node was
enforcing, this was due to the destination being the first HV built and therefore
provisioned slightly differently, my kickstart server is a VM in the pool.
Its interesting that a VM can be provisioned onto a node that is set to enforcing and yet
not migrated to.
thanks
6:11 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
On Wed, Jan 09, 2013 at 10:06:12AM +0000, Tom Brown wrote:
>> libvirtError: internal error Process exited while reading console log outpu
> could this be related to selinux? can you try disabling it and see if migration
succeeds?
It was indeed the case! my src node was set to disabled and my destination node was
enforcing, this was due to the destination being the first HV built and therefore
provisioned slightly differently, my kickstart server is a VM in the pool.
Its interesting that a VM can be provisioned onto a node that is set to enforcing and yet
not migrated to.
I have (only a vague) memory of discussing this already...
Shouldn't oVirt-Engine be aware of selinux enforcement? If a cluster has
disabled hosts, an enforcing host should not be operational (or at least
warn the admin about that).
8:05 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
----- Original Message -----
From: "Dan Kenigsberg" <danken(a)redhat.com>
To: "Tom Brown" <tom(a)ng23.net>
Cc: "Simon Grinberg" <sgrinber(a)redhat.com>, users(a)ovirt.org
Sent: Wednesday, January 9, 2013 2:11:14 PM
Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
On Wed, Jan 09, 2013 at 10:06:12AM +0000, Tom Brown wrote:
>
>
> >> libvirtError: internal error Process exited while reading
> >> console log outpu
> > could this be related to selinux? can you try disabling it and
> > see if migration succeeds?
>
> It was indeed the case! my src node was set to disabled and my
> destination node was enforcing, this was due to the destination
> being the first HV built and therefore provisioned slightly
> differently, my kickstart server is a VM in the pool.
>
> Its interesting that a VM can be provisioned onto a node that is
> set to enforcing and yet not migrated to.
I have (only a vague) memory of discussing this already...
Shouldn't oVirt-Engine be aware of selinux enforcement? If a cluster
has
disabled hosts, an enforcing host should not be operational (or at
least
warn the admin about that).
I recall something like that, but I don't recall we ever converged and can't find
the thread
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
10:20 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
On Wed, Jan 09, 2013 at 09:05:37AM -0500, Simon Grinberg wrote:
----- Original Message -----
> From: "Dan Kenigsberg" <danken(a)redhat.com>
> To: "Tom Brown" <tom(a)ng23.net>
> Cc: "Simon Grinberg" <sgrinber(a)redhat.com>, users(a)ovirt.org
> Sent: Wednesday, January 9, 2013 2:11:14 PM
> Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
>
> On Wed, Jan 09, 2013 at 10:06:12AM +0000, Tom Brown wrote:
> >
> >
> > >> libvirtError: internal error Process exited while reading
> > >> console log outpu
> > > could this be related to selinux? can you try disabling it and
> > > see if migration succeeds?
> >
> > It was indeed the case! my src node was set to disabled and my
> > destination node was enforcing, this was due to the destination
> > being the first HV built and therefore provisioned slightly
> > differently, my kickstart server is a VM in the pool.
> >
> > Its interesting that a VM can be provisioned onto a node that is
> > set to enforcing and yet not migrated to.
>
> I have (only a vague) memory of discussing this already...
> Shouldn't oVirt-Engine be aware of selinux enforcement? If a cluster
> has
> disabled hosts, an enforcing host should not be operational (or at
> least
> warn the admin about that).
I recall something like that, but I don't recall we ever converged and can't find
the thread
What is your opinion on the subject?
I think that at the least, the scheduler must be aware of selinux
enforcement when it chooses migration destination.
10:34 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
----- Original Message -----
From: "Dan Kenigsberg" <danken(a)redhat.com>
To: "Simon Grinberg" <simon(a)redhat.com>
Cc: users(a)ovirt.org, "Tom Brown" <tom(a)ng23.net>
Sent: Wednesday, January 9, 2013 6:20:02 PM
Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
On Wed, Jan 09, 2013 at 09:05:37AM -0500, Simon Grinberg wrote:
>
>
> ----- Original Message -----
> > From: "Dan Kenigsberg" <danken(a)redhat.com>
> > To: "Tom Brown" <tom(a)ng23.net>
> > Cc: "Simon Grinberg" <sgrinber(a)redhat.com>, users(a)ovirt.org
> > Sent: Wednesday, January 9, 2013 2:11:14 PM
> > Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
> >
> > On Wed, Jan 09, 2013 at 10:06:12AM +0000, Tom Brown wrote:
> > >
> > >
> > > >> libvirtError: internal error Process exited while reading
> > > >> console log outpu
> > > > could this be related to selinux? can you try disabling it
> > > > and
> > > > see if migration succeeds?
> > >
> > > It was indeed the case! my src node was set to disabled and my
> > > destination node was enforcing, this was due to the destination
> > > being the first HV built and therefore provisioned slightly
> > > differently, my kickstart server is a VM in the pool.
> > >
> > > Its interesting that a VM can be provisioned onto a node that
> > > is
> > > set to enforcing and yet not migrated to.
> >
> > I have (only a vague) memory of discussing this already...
> > Shouldn't oVirt-Engine be aware of selinux enforcement? If a
> > cluster
> > has
> > disabled hosts, an enforcing host should not be operational (or
> > at
> > least
> > warn the admin about that).
>
>
> I recall something like that, but I don't recall we ever converged
> and can't find the thread
What is your opinion on the subject?
I think that at the least, the scheduler must be aware of selinux
enforcement when it chooses migration destination.
Either all or non in the same cluster - that is the default.
On a mixed environment, the non enforced hosts should be move to non-operational, but VM
should not be migrated off due to this, we don't want them moved to protected hosts
without the admin awareness.
As exception to the above, have a config parameter that allows in a mixed environment to
migrate VMs from an insecure onto a secure host never the other way around. This is to
support transition from non-enabled system to enabled.
I think this is the closest I can get to the agreement (or at least concerns) raised in
that old thread I can't find.
6:09 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
On Wed, Jan 09, 2013 at 11:34:56AM -0500, Simon Grinberg wrote:
----- Original Message -----
> From: "Dan Kenigsberg" <danken(a)redhat.com>
> To: "Simon Grinberg" <simon(a)redhat.com>
> Cc: users(a)ovirt.org, "Tom Brown" <tom(a)ng23.net>
> Sent: Wednesday, January 9, 2013 6:20:02 PM
> Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
>
> On Wed, Jan 09, 2013 at 09:05:37AM -0500, Simon Grinberg wrote:
> >
> >
> > ----- Original Message -----
> > > From: "Dan Kenigsberg" <danken(a)redhat.com>
> > > To: "Tom Brown" <tom(a)ng23.net>
> > > Cc: "Simon Grinberg" <sgrinber(a)redhat.com>,
users(a)ovirt.org
> > > Sent: Wednesday, January 9, 2013 2:11:14 PM
> > > Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
> > >
> > > On Wed, Jan 09, 2013 at 10:06:12AM +0000, Tom Brown wrote:
> > > >
> > > >
> > > > >> libvirtError: internal error Process exited while reading
> > > > >> console log outpu
> > > > > could this be related to selinux? can you try disabling it
> > > > > and
> > > > > see if migration succeeds?
> > > >
> > > > It was indeed the case! my src node was set to disabled and my
> > > > destination node was enforcing, this was due to the destination
> > > > being the first HV built and therefore provisioned slightly
> > > > differently, my kickstart server is a VM in the pool.
> > > >
> > > > Its interesting that a VM can be provisioned onto a node that
> > > > is
> > > > set to enforcing and yet not migrated to.
> > >
> > > I have (only a vague) memory of discussing this already...
> > > Shouldn't oVirt-Engine be aware of selinux enforcement? If a
> > > cluster
> > > has
> > > disabled hosts, an enforcing host should not be operational (or
> > > at
> > > least
> > > warn the admin about that).
> >
> >
> > I recall something like that, but I don't recall we ever converged
> > and can't find the thread
>
> What is your opinion on the subject?
>
> I think that at the least, the scheduler must be aware of selinux
> enforcement when it chooses migration destination.
>
Either all or non in the same cluster - that is the default.
On a mixed environment, the non enforced hosts should be move to non-operational, but VM
should not be migrated off due to this, we don't want them moved to protected hosts
without the admin awareness.
As exception to the above, have a config parameter that allows in a mixed environment to
migrate VMs from an insecure onto a secure host never the other way around. This is to
support transition from non-enabled system to enabled.
Please see Tom's report above:
> > > > It was indeed the case! my src node was set to
disabled and my
> > > > destination node was enforcing ...
We apparently cannot migrate an insecure guest into an enforcing system.
I think this is the closest I can get to the agreement (or at least concerns) raised in
that old thread I can't find.
6:41 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
----- Original Message -----
From: "Dan Kenigsberg" <danken(a)redhat.com>
To: "Simon Grinberg" <simon(a)redhat.com>
Cc: users(a)ovirt.org, "Tom Brown" <tom(a)ng23.net>
Sent: Thursday, January 10, 2013 2:09:28 PM
Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
On Wed, Jan 09, 2013 at 11:34:56AM -0500, Simon Grinberg wrote:
>
>
> ----- Original Message -----
> > From: "Dan Kenigsberg" <danken(a)redhat.com>
> > To: "Simon Grinberg" <simon(a)redhat.com>
> > Cc: users(a)ovirt.org, "Tom Brown" <tom(a)ng23.net>
> > Sent: Wednesday, January 9, 2013 6:20:02 PM
> > Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
> >
> > On Wed, Jan 09, 2013 at 09:05:37AM -0500, Simon Grinberg wrote:
> > >
> > >
> > > ----- Original Message -----
> > > > From: "Dan Kenigsberg" <danken(a)redhat.com>
> > > > To: "Tom Brown" <tom(a)ng23.net>
> > > > Cc: "Simon Grinberg" <sgrinber(a)redhat.com>,
users(a)ovirt.org
> > > > Sent: Wednesday, January 9, 2013 2:11:14 PM
> > > > Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
> > > >
> > > > On Wed, Jan 09, 2013 at 10:06:12AM +0000, Tom Brown wrote:
> > > > >
> > > > >
> > > > > >> libvirtError: internal error Process exited while
> > > > > >> reading
> > > > > >> console log outpu
> > > > > > could this be related to selinux? can you try disabling
> > > > > > it
> > > > > > and
> > > > > > see if migration succeeds?
> > > > >
> > > > > It was indeed the case! my src node was set to disabled and
> > > > > my
> > > > > destination node was enforcing, this was due to the
> > > > > destination
> > > > > being the first HV built and therefore provisioned slightly
> > > > > differently, my kickstart server is a VM in the pool.
> > > > >
> > > > > Its interesting that a VM can be provisioned onto a node
> > > > > that
> > > > > is
> > > > > set to enforcing and yet not migrated to.
> > > >
> > > > I have (only a vague) memory of discussing this already...
> > > > Shouldn't oVirt-Engine be aware of selinux enforcement? If a
> > > > cluster
> > > > has
> > > > disabled hosts, an enforcing host should not be operational
> > > > (or
> > > > at
> > > > least
> > > > warn the admin about that).
> > >
> > >
> > > I recall something like that, but I don't recall we ever
> > > converged
> > > and can't find the thread
> >
> > What is your opinion on the subject?
> >
> > I think that at the least, the scheduler must be aware of selinux
> > enforcement when it chooses migration destination.
> >
>
> Either all or non in the same cluster - that is the default.
>
> On a mixed environment, the non enforced hosts should be move to
> non-operational, but VM should not be migrated off due to this, we
> don't want them moved to protected hosts without the admin
> awareness.
>
> As exception to the above, have a config parameter that allows in a
> mixed environment to migrate VMs from an insecure onto a secure
> host never the other way around. This is to support transition
> from non-enabled system to enabled.
Please see Tom's report above:
> > > > > It was indeed the case! my src node was set to disabled and
> > > > > my
> > > > > destination node was enforcing ...
We apparently cannot migrate an insecure guest into an enforcing
system.
Well you've asked for my opinion not current implementation :)
I'm not sure anything was implemented on the selinux requirements, need to check this,
the error I see in this thread is run time failure due to improper setting, which is to be
expected on migration from non labelled zone into a labelled zone.
>
> I think this is the closest I can get to the agreement (or at least
> concerns) raised in that old thread I can't find.
2:03 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
Source or destination?
On 9 Jan 2013, at 07:35, Haim Ateya <hateya(a)redhat.com> wrote:
odd,
migration seem to be successful on destination server, but source reports a problem:
Thread-1484336::DEBUG::2013-01-08 10:41:07,659::BindingXMLRPC::883::vds::(wrapper) client
[10.192.42.207]::call vmMigrate with ({'src': '10.192.42.196',
'dst': '10.192.42.165:54321', 'vmId': 'cfb17b98-1476-4fbf-9f
Thread-1484336::DEBUG::2013-01-08 10:41:07,659::API::432::vds::(migrate) {'src':
'10.192.42.196', 'dst': '10.192.42.165:54321', 'vmId':
'cfb17b98-1476-4fbf-9fab-7c7f48b60adf', 'method': 'online'}
Thread-1484337::DEBUG::2013-01-08 10:41:07,660::vm::125::vm.Vm::(_setupVdsConnection)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Destination server is: 10.192.42.165:54321
Thread-1484336::DEBUG::2013-01-08 10:41:07,660::BindingXMLRPC::890::vds::(wrapper) return
vmMigrate with {'status': {'message': 'Migration process
starting', 'code': 0}}
Thread-1484337::DEBUG::2013-01-08 10:41:07,660::vm::127::vm.Vm::(_setupVdsConnection)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Initiating connection with destination
Thread-1484337::DEBUG::2013-01-08 10:41:07,752::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk vda latency not available
Thread-1484337::DEBUG::2013-01-08 10:41:07,835::vm::173::vm.Vm::(_prepareGuest)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration Process begins
Thread-1484337::DEBUG::2013-01-08 10:41:07,927::vm::237::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration semaphore acquired
Thread-1484337::DEBUG::2013-01-08
10:41:08,251::libvirtvm::449::vm.Vm::(_startUnderlyingMigration)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::starting migration to
qemu+tls://10.192.42.165/system
Thread-1484338::DEBUG::2013-01-08 10:41:08,251::libvirtvm::335::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration downtime thread started
Thread-1484339::DEBUG::2013-01-08 10:41:08,252::libvirtvm::371::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::starting migration monitor thread
Thread-1484337::DEBUG::2013-01-08 10:41:09,521::libvirtvm::350::vm.Vm::(cancel)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::canceling migration downtime thread
Thread-1484337::DEBUG::2013-01-08 10:41:09,521::libvirtvm::409::vm.Vm::(stop)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::stopping migration monitor thread
Thread-1484338::DEBUG::2013-01-08 10:41:09,522::libvirtvm::347::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration downtime thread exiting
Thread-1484337::ERROR::2013-01-08 10:41:09,522::vm::179::vm.Vm::(_recover)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::internal error Process exited while reading
console log output:
Thread-1484340::DEBUG::2013-01-08
10:41:09,544::task::568::TaskManager.Task::(_updateState)
Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::moving from state init -> state preparing
Thread-1484340::INFO::2013-01-08 10:41:09,544::logUtils::37::dispatcher::(wrapper) Run
and protect: repoStats(options=None)
Thread-1484340::INFO::2013-01-08 10:41:09,544::logUtils::39::dispatcher::(wrapper) Run
and protect: repoStats, Return response: {'2a1939bd-9fa3-4896-b8a9-46234172aae7':
{'delay': '0.00229001045227', 'lastCheck': '
Thread-1484340::DEBUG::2013-01-08 10:41:09,544::task::1151::TaskManager.Task::(prepare)
Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::finished:
{'2a1939bd-9fa3-4896-b8a9-46234172aae7': {'delay':
'0.00229001045227',
Thread-1484340::DEBUG::2013-01-08
10:41:09,544::task::568::TaskManager.Task::(_updateState)
Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::moving from state preparing -> state
finished
Thread-1484340::DEBUG::2013-01-08
10:41:09,545::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
Thread-1484340::DEBUG::2013-01-08
10:41:09,545::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
Thread-1484340::DEBUG::2013-01-08 10:41:09,545::task::957::TaskManager.Task::(_decref)
Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::ref 0 aborting False
Thread-1484341::DEBUG::2013-01-08 10:41:09,558::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk vda latency not available
Thread-1484341::DEBUG::2013-01-08 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`7b8f725b-0a67-46d4-a3cf-db43daad0c42`::Disk vda latency not available
Thread-1484341::DEBUG::2013-01-08 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`9dc63ce4-0f76-4963-adfe-6f8eb1a44806`::Disk vda latency not available
Thread-1484341::DEBUG::2013-01-08 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
vmId=`e8683e88-f3f2-4fe9-80f7-f4888d8e7a13`::Disk vda latency not available
Thread-1484337::ERROR::2013-01-08 10:41:09,754::vm::258::vm.Vm::(run)
vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Failed to migrate
Traceback (most recent call last):
File "/usr/share/vdsm/vm.py", line 245, in run
self._startUnderlyingMigration()
File "/usr/share/vdsm/libvirtvm.py", line 474, in _startUnderlyingMigration
None, maxBandwidth)
File "/usr/share/vdsm/libvirtvm.py", line 510, in f
ret = attr(*args, **kwargs)
File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 83,
in wrapper
ret = f(*args, **kwargs)
File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1103, in
migrateToURI2
if ret == -1: raise libvirtError ('virDomainMigrateToURI2() failed',
dom=self)
libvirtError: internal error Process exited while reading console log output:
any chance you attach libvirtd.log and qemu log (/var/log/libvirt/qemu/{}.log?
Danken - any insights?
----- Original Message -----
> From: "Tom Brown" <tom(a)ng23.net>
> To: "Roy Golan" <rgolan(a)redhat.com>
> Cc: "Haim Ateya" <hateya(a)redhat.com>, users(a)ovirt.org
> Sent: Tuesday, January 8, 2013 11:50:26 AM
> Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
>
>
>> can you attach the same snip from the src VDSM 10.192.42.196 as
>> well?
>
> The log is pretty chatty therefore i did another migration attempt
> and snipd'd the new
> log from both sides.
>
> see attached
>
>
2:32 a.m.
New subject: [Users] oVirt 3.1 - VM Migration Issue
both.
----- Original Message -----
From: "Tom Brown" <tom(a)ng23.net>
To: "Haim Ateya" <hateya(a)redhat.com>
Cc: "Dan Kenigsberg" <danken(a)redhat.com>, users(a)ovirt.org, "Roy
Golan" <rgolan(a)redhat.com>
Sent: Wednesday, January 9, 2013 10:03:11 AM
Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
Source or destination?
On 9 Jan 2013, at 07:35, Haim Ateya <hateya(a)redhat.com> wrote:
> odd,
>
> migration seem to be successful on destination server, but source
> reports a problem:
>
> Thread-1484336::DEBUG::2013-01-08
> 10:41:07,659::BindingXMLRPC::883::vds::(wrapper) client
> [10.192.42.207]::call vmMigrate with ({'src': '10.192.42.196',
> 'dst': '10.192.42.165:54321', 'vmId':
'cfb17b98-1476-4fbf-9f
> Thread-1484336::DEBUG::2013-01-08
> 10:41:07,659::API::432::vds::(migrate) {'src': '10.192.42.196',
> 'dst': '10.192.42.165:54321', 'vmId':
> 'cfb17b98-1476-4fbf-9fab-7c7f48b60adf', 'method': 'online'}
> Thread-1484337::DEBUG::2013-01-08
> 10:41:07,660::vm::125::vm.Vm::(_setupVdsConnection)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Destination server
> is: 10.192.42.165:54321
> Thread-1484336::DEBUG::2013-01-08
> 10:41:07,660::BindingXMLRPC::890::vds::(wrapper) return vmMigrate
> with {'status': {'message': 'Migration process starting',
'code':
> 0}}
> Thread-1484337::DEBUG::2013-01-08
> 10:41:07,660::vm::127::vm.Vm::(_setupVdsConnection)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Initiating connection
> with destination
> Thread-1484337::DEBUG::2013-01-08
> 10:41:07,752::libvirtvm::278::vm.Vm::(_getDiskLatency)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk vda latency not
> available
> Thread-1484337::DEBUG::2013-01-08
> 10:41:07,835::vm::173::vm.Vm::(_prepareGuest)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration Process
> begins
> Thread-1484337::DEBUG::2013-01-08
> 10:41:07,927::vm::237::vm.Vm::(run)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration semaphore
> acquired
> Thread-1484337::DEBUG::2013-01-08
> 10:41:08,251::libvirtvm::449::vm.Vm::(_startUnderlyingMigration)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::starting migration to
> qemu+tls://10.192.42.165/system
> Thread-1484338::DEBUG::2013-01-08
> 10:41:08,251::libvirtvm::335::vm.Vm::(run)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration downtime
> thread started
> Thread-1484339::DEBUG::2013-01-08
> 10:41:08,252::libvirtvm::371::vm.Vm::(run)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::starting migration
> monitor thread
> Thread-1484337::DEBUG::2013-01-08
> 10:41:09,521::libvirtvm::350::vm.Vm::(cancel)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::canceling migration
> downtime thread
> Thread-1484337::DEBUG::2013-01-08
> 10:41:09,521::libvirtvm::409::vm.Vm::(stop)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::stopping migration
> monitor thread
> Thread-1484338::DEBUG::2013-01-08
> 10:41:09,522::libvirtvm::347::vm.Vm::(run)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::migration downtime
> thread exiting
> Thread-1484337::ERROR::2013-01-08
> 10:41:09,522::vm::179::vm.Vm::(_recover)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::internal error
> Process exited while reading console log output:
> Thread-1484340::DEBUG::2013-01-08
> 10:41:09,544::task::568::TaskManager.Task::(_updateState)
> Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::moving from state
> init -> state preparing
> Thread-1484340::INFO::2013-01-08
> 10:41:09,544::logUtils::37::dispatcher::(wrapper) Run and protect:
> repoStats(options=None)
> Thread-1484340::INFO::2013-01-08
> 10:41:09,544::logUtils::39::dispatcher::(wrapper) Run and protect:
> repoStats, Return response:
> {'2a1939bd-9fa3-4896-b8a9-46234172aae7': {'delay':
> '0.00229001045227', 'lastCheck': '
> Thread-1484340::DEBUG::2013-01-08
> 10:41:09,544::task::1151::TaskManager.Task::(prepare)
> Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::finished:
> {'2a1939bd-9fa3-4896-b8a9-46234172aae7': {'delay':
> '0.00229001045227',
> Thread-1484340::DEBUG::2013-01-08
> 10:41:09,544::task::568::TaskManager.Task::(_updateState)
> Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::moving from state
> preparing -> state finished
> Thread-1484340::DEBUG::2013-01-08
> 10:41:09,545::resourceManager::809::ResourceManager.Owner::(releaseAll)
> Owner.releaseAll requests {} resources {}
> Thread-1484340::DEBUG::2013-01-08
> 10:41:09,545::resourceManager::844::ResourceManager.Owner::(cancelAll)
> Owner.cancelAll requests {}
> Thread-1484340::DEBUG::2013-01-08
> 10:41:09,545::task::957::TaskManager.Task::(_decref)
> Task=`bfebf940-d2a3-4b6c-948b-cac951a686bf`::ref 0 aborting False
> Thread-1484341::DEBUG::2013-01-08
> 10:41:09,558::libvirtvm::278::vm.Vm::(_getDiskLatency)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Disk vda latency not
> available
> Thread-1484341::DEBUG::2013-01-08
> 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
> vmId=`7b8f725b-0a67-46d4-a3cf-db43daad0c42`::Disk vda latency not
> available
> Thread-1484341::DEBUG::2013-01-08
> 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
> vmId=`9dc63ce4-0f76-4963-adfe-6f8eb1a44806`::Disk vda latency not
> available
> Thread-1484341::DEBUG::2013-01-08
> 10:41:09,559::libvirtvm::278::vm.Vm::(_getDiskLatency)
> vmId=`e8683e88-f3f2-4fe9-80f7-f4888d8e7a13`::Disk vda latency not
> available
> Thread-1484337::ERROR::2013-01-08
> 10:41:09,754::vm::258::vm.Vm::(run)
> vmId=`cfb17b98-1476-4fbf-9fab-7c7f48b60adf`::Failed to migrate
> Traceback (most recent call last):
> File "/usr/share/vdsm/vm.py", line 245, in run
> self._startUnderlyingMigration()
> File "/usr/share/vdsm/libvirtvm.py", line 474, in
> _startUnderlyingMigration
> None, maxBandwidth)
> File "/usr/share/vdsm/libvirtvm.py", line 510, in f
> ret = attr(*args, **kwargs)
> File
> "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py",
> line 83, in wrapper
> ret = f(*args, **kwargs)
> File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1103,
> in migrateToURI2
> if ret == -1: raise libvirtError ('virDomainMigrateToURI2()
> failed', dom=self)
> libvirtError: internal error Process exited while reading console
> log output:
>
> any chance you attach libvirtd.log and qemu log
> (/var/log/libvirt/qemu/{}.log?
>
> Danken - any insights?
>
> ----- Original Message -----
>> From: "Tom Brown" <tom(a)ng23.net>
>> To: "Roy Golan" <rgolan(a)redhat.com>
>> Cc: "Haim Ateya" <hateya(a)redhat.com>, users(a)ovirt.org
>> Sent: Tuesday, January 8, 2013 11:50:26 AM
>> Subject: Re: [Users] oVirt 3.1 - VM Migration Issue
>>
>>
>>> can you attach the same snip from the src VDSM 10.192.42.196 as
>>> well?
>>
>> The log is pretty chatty therefore i did another migration attempt
>> and snipd'd the new
>> log from both sides.
>>
>> see attached
>>
>>
4445
days inactive
4449
days old
15 comments
5 participants
participants (5)
-
Dan Kenigsberg -
Haim Ateya -
Roy Golan -
Simon Grinberg -
Tom Brown