Note: This bug is displayed in read-only format because
the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Comment 4RHEL Program Management
2012-12-14 08:52:24 UTC
This request was not resolved in time for the current release.
Red Hat invites you to ask your support representative to
propose this request, if still desired, for consideration in
the next release of Red Hat Enterprise Linux.
Description of problem: I tried (by mistake) migrate a VM with USB 'Native' support and got useless failure message: VM rhel6_ws_32bit is down. Exit message: Domain not found: no domain with matching uuid '2545aff1-dde2-4ce1-9de6-da6e82e8fa5c'. 'Migration is NOT currently supported using SPICE Native USB redirection Advanced Parameters' is visible in VM->Edit->Console popup but failure message tells nothing to the user. I would expect some useful failure message. Version-Release number of selected component (if applicable): SI24.5 + vdsm44.1 How reproducible: 100% Steps to Reproduce: 1. Have a VM with USB 'Native' support. 2. Try to migrate. 3. Check in Web admin portal the failure message. Actual results: Useless failure message. Expected results: Useful failure message. Additional info: See logs below which make issue even more confusing. web admin portal ================ 2012-Dec-06, 16:09 VM rhel6_ws_32bit is down. Exit message: Domain not found: no domain with matching uuid '2545aff1-dde2-4ce1-9de6-da6e82e8fa5c'. 2012-Dec-06, 16:09 Starting migration of VM rhel6_ws_32bit from Host dell-r210ii-04 to Host dell-r210ii-03 (User: admin@internal.). engine.log ========== 2012-12-06 16:09:39,757 INFO [org.ovirt.engine.core.bll.MigrateVmCommand] (pool-3-thread-50) [791542cc] Running command: MigrateVmCommand internal: false. Entities affected : ID: 2545aff1-dde2-4ce1-9de6-da6e82e8fa5c Type: VM 2012-12-06 16:09:39,770 INFO [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] (pool-3-thread-50) [791542cc] START, MigrateVDSCommand(HostName = dell-r210ii-04, HostId = fb65e1d2-3a3a-11e2-9003-001a4a013f3c, vmId=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c, srcHost=dell-r210ii-04.rhev.lab.eng.brq.redhat.com, dstVdsId=fe170110-34a7-11e2-b21d-001a4a013f3c, dstHost=dell-r210ii-03.rhev.lab.eng.brq.redhat.com:54321, migrationMethod=ONLINE), log id: 362aff5c 2012-12-06 16:09:39,771 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (pool-3-thread-50) [791542cc] VdsBroker::migrate::Entered (vm_guid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c, srcHost=dell-r210ii-04.rhev.lab.eng.brq.redhat.com, dstHost=dell-r210ii-03.rhev.lab.eng.brq.redhat.com:54321, method=online 2012-12-06 16:09:39,771 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (pool-3-thread-50) [791542cc] START, MigrateBrokerVDSCommand(HostName = dell-r210ii-04, HostId = fb65e1d2-3a3a-11e2-9003-001a4a013f3c, vmId=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c, srcHost=dell-r210ii-04.rhev.lab.eng.brq.redhat.com, dstVdsId=fe170110-34a7-11e2-b21d-001a4a013f3c, dstHost=dell-r210ii-03.rhev.lab.eng.brq.redhat.com:54321, migrationMethod=ONLINE), log id: 53d44458 2012-12-06 16:09:39,792 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (pool-3-thread-50) [791542cc] FINISH, MigrateBrokerVDSCommand, log id: 53d44458 2012-12-06 16:09:39,807 INFO [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] (pool-3-thread-50) [791542cc] FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 362aff5c 2012-12-06 16:09:47,043 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzScheduler_Worker-62) START, DestroyVDSCommand(HostName = dell-r210ii-03, HostId = fe170110-34a7-11e2-b21d-001a4a013f3c, vmId=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c, force=false, secondsToWait=0, gracefully=false), log id: 1fc630ff 2012-12-06 16:09:51,663 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (QuartzScheduler_Worker-62) Failed in DestroyVDS method 2012-12-06 16:09:51,663 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (QuartzScheduler_Worker-62) Error code noVM and error message VDSGenericException: VDSErrorException: Failed to DestroyVDS, error = Virtual machine does not exist 2012-12-06 16:09:51,664 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (QuartzScheduler_Worker-62) Command org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand return value Class Name: org.ovirt.engine.core.vdsbroker.vdsbroker.StatusOnlyReturnForXmlRpc mStatus Class Name: org.ovirt.engine.core.vdsbroker.vdsbroker.StatusForXmlRpc mCode 1 mMessage Virtual machine does not exist 2012-12-06 16:09:51,664 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (QuartzScheduler_Worker-62) HostName = dell-r210ii-03 2012-12-06 16:09:51,664 ERROR [org.ovirt.engine.core.vdsbroker.VDSCommandBase] (QuartzScheduler_Worker-62) Command DestroyVDS execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed to DestroyVDS, error = Virtual machine does not exist 2012-12-06 16:09:51,664 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzScheduler_Worker-62) FINISH, DestroyVDSCommand, log id: 1fc630ff 2012-12-06 16:09:51,710 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-62) vds::refreshVmList vm id 2545aff1-dde2-4ce1-9de6-da6e82e8fa5c status = Down on vds dell-r210ii-03 ignoring it in the refresh until migration is done 2012-12-06 16:09:52,960 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-30) VM rhel6_ws_32bit 2545aff1-dde2-4ce1-9de6-da6e82e8fa5c moved from MigratingFrom --> Up 2012-12-06 16:09:52,960 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-30) adding VM 2545aff1-dde2-4ce1-9de6-da6e82e8fa5c to re-run list 2012-12-06 16:09:52,973 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-30) Rerun vm 2545aff1-dde2-4ce1-9de6-da6e82e8fa5c. Called from vds dell-r210ii-04 2012-12-06 16:10:00,000 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-42) Checking autorecoverable hosts 2012-12-06 16:10:00,004 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-42) Autorecovering 0 hosts 2012-12-06 16:10:00,004 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-42) Checking autorecoverable hosts done 2012-12-06 16:10:00,004 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-42) Autorecovering storage domains is disabled, skipping vdsm.log ======== Thread-3058::DEBUG::2012-12-06 16:09:07,372::task::588::TaskManager.Task::(_updateState) Task=`e5ca3f13-0fea-4de1-bf1e-46cfcb3cc142`::moving from state init -> state preparing Thread-3058::INFO::2012-12-06 16:09:07,373::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-3058::INFO::2012-12-06 16:09:07,373::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00119090080261', 'lastCheck': '0.7', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.000998973846436', 'lastCheck': '0.7', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.00122690200806', 'lastCheck': '9.1', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00117588043213', 'lastCheck': '0.7', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00128102302551', 'lastCheck': '9.3', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00176692008972', 'lastCheck': '9.8', 'code': 0, 'valid': True}} Thread-3058::DEBUG::2012-12-06 16:09:07,373::task::1172::TaskManager.Task::(prepare) Task=`e5ca3f13-0fea-4de1-bf1e-46cfcb3cc142`::finished: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00119090080261', 'lastCheck': '0.7', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.000998973846436', 'lastCheck': '0.7', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.00122690200806', 'lastCheck': '9.1', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00117588043213', 'lastCheck': '0.7', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00128102302551', 'lastCheck': '9.3', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00176692008972', 'lastCheck': '9.8', 'code': 0, 'valid': True}} Thread-3058::DEBUG::2012-12-06 16:09:07,373::task::588::TaskManager.Task::(_updateState) Task=`e5ca3f13-0fea-4de1-bf1e-46cfcb3cc142`::moving from state preparing -> state finished Thread-3058::DEBUG::2012-12-06 16:09:07,374::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-3058::DEBUG::2012-12-06 16:09:07,374::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-3058::DEBUG::2012-12-06 16:09:07,374::task::978::TaskManager.Task::(_decref) Task=`e5ca3f13-0fea-4de1-bf1e-46cfcb3cc142`::ref 0 aborting False Thread-3059::DEBUG::2012-12-06 16:09:07,397::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3064::DEBUG::2012-12-06 16:09:17,665::task::588::TaskManager.Task::(_updateState) Task=`6993d14a-0913-4022-88eb-ffdc28ee330a`::moving from state init -> state preparing Thread-3064::INFO::2012-12-06 16:09:17,665::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-3064::INFO::2012-12-06 16:09:17,665::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00207090377808', 'lastCheck': '1.0', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.00102710723877', 'lastCheck': '1.0', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.00112295150757', 'lastCheck': '9.4', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00137901306152', 'lastCheck': '1.0', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00107288360596', 'lastCheck': '9.5', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00164318084717', 'lastCheck': '0.1', 'code': 0, 'valid': True}} Thread-3064::DEBUG::2012-12-06 16:09:17,665::task::1172::TaskManager.Task::(prepare) Task=`6993d14a-0913-4022-88eb-ffdc28ee330a`::finished: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00207090377808', 'lastCheck': '1.0', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.00102710723877', 'lastCheck': '1.0', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.00112295150757', 'lastCheck': '9.4', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00137901306152', 'lastCheck': '1.0', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00107288360596', 'lastCheck': '9.5', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00164318084717', 'lastCheck': '0.1', 'code': 0, 'valid': True}} Thread-3064::DEBUG::2012-12-06 16:09:17,666::task::588::TaskManager.Task::(_updateState) Task=`6993d14a-0913-4022-88eb-ffdc28ee330a`::moving from state preparing -> state finished Thread-3064::DEBUG::2012-12-06 16:09:17,666::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-3064::DEBUG::2012-12-06 16:09:17,666::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-3064::DEBUG::2012-12-06 16:09:17,666::task::978::TaskManager.Task::(_decref) Task=`6993d14a-0913-4022-88eb-ffdc28ee330a`::ref 0 aborting False Thread-3065::DEBUG::2012-12-06 16:09:17,688::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available VM Channels Listener::DEBUG::2012-12-06 16:09:27,838::vmChannels::60::vds::(_handle_timeouts) Timeout on fileno 82. Thread-3070::DEBUG::2012-12-06 16:09:27,973::task::588::TaskManager.Task::(_updateState) Task=`93568f18-5643-4655-b84d-62f1b1efb1e6`::moving from state init -> state preparing Thread-3070::INFO::2012-12-06 16:09:27,973::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-3070::INFO::2012-12-06 16:09:27,974::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00197100639343', 'lastCheck': '1.3', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.00104403495789', 'lastCheck': '1.3', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.00123906135559', 'lastCheck': '9.7', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00113487243652', 'lastCheck': '1.3', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00124287605286', 'lastCheck': '9.8', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.0016028881073', 'lastCheck': '0.4', 'code': 0, 'valid': True}} Thread-3070::DEBUG::2012-12-06 16:09:27,974::task::1172::TaskManager.Task::(prepare) Task=`93568f18-5643-4655-b84d-62f1b1efb1e6`::finished: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00197100639343', 'lastCheck': '1.3', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.00104403495789', 'lastCheck': '1.3', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.00123906135559', 'lastCheck': '9.7', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00113487243652', 'lastCheck': '1.3', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00124287605286', 'lastCheck': '9.8', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.0016028881073', 'lastCheck': '0.4', 'code': 0, 'valid': True}} Thread-3070::DEBUG::2012-12-06 16:09:27,974::task::588::TaskManager.Task::(_updateState) Task=`93568f18-5643-4655-b84d-62f1b1efb1e6`::moving from state preparing -> state finished Thread-3070::DEBUG::2012-12-06 16:09:27,974::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-3070::DEBUG::2012-12-06 16:09:27,975::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-3070::DEBUG::2012-12-06 16:09:27,975::task::978::TaskManager.Task::(_decref) Task=`93568f18-5643-4655-b84d-62f1b1efb1e6`::ref 0 aborting False Thread-3071::DEBUG::2012-12-06 16:09:27,998::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3076::DEBUG::2012-12-06 16:09:38,341::task::588::TaskManager.Task::(_updateState) Task=`55ce20da-dad1-4981-b396-af2142b67992`::moving from state init -> state preparing Thread-3076::INFO::2012-12-06 16:09:38,341::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-3076::INFO::2012-12-06 16:09:38,341::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00218081474304', 'lastCheck': '1.6', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.00118112564087', 'lastCheck': '1.6', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.0011248588562', 'lastCheck': '0.0', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.0010199546814', 'lastCheck': '1.7', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00100517272949', 'lastCheck': '0.2', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00123715400696', 'lastCheck': '0.7', 'code': 0, 'valid': True}} Thread-3076::DEBUG::2012-12-06 16:09:38,341::task::1172::TaskManager.Task::(prepare) Task=`55ce20da-dad1-4981-b396-af2142b67992`::finished: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00218081474304', 'lastCheck': '1.6', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.00118112564087', 'lastCheck': '1.6', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.0011248588562', 'lastCheck': '0.0', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.0010199546814', 'lastCheck': '1.7', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00100517272949', 'lastCheck': '0.2', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00123715400696', 'lastCheck': '0.7', 'code': 0, 'valid': True}} Thread-3076::DEBUG::2012-12-06 16:09:38,342::task::588::TaskManager.Task::(_updateState) Task=`55ce20da-dad1-4981-b396-af2142b67992`::moving from state preparing -> state finished Thread-3076::DEBUG::2012-12-06 16:09:38,342::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-3076::DEBUG::2012-12-06 16:09:38,342::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-3076::DEBUG::2012-12-06 16:09:38,342::task::978::TaskManager.Task::(_decref) Task=`55ce20da-dad1-4981-b396-af2142b67992`::ref 0 aborting False Thread-3077::DEBUG::2012-12-06 16:09:38,365::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3078::DEBUG::2012-12-06 16:09:39,792::BindingXMLRPC::894::vds::(wrapper) client [10.34.63.75]::call vmMigrate with ({'src': 'dell-r210ii-04.rhev.lab.eng.brq.redhat.com', 'dst': 'dell-r210ii-03.rhev.lab.eng.brq.redhat.com:54321', 'vmId': '2545aff1-dde2-4ce1-9de6-da6e82e8fa5c', 'method': 'online'},) {} flowID [791542cc] Thread-3078::DEBUG::2012-12-06 16:09:39,792::API::421::vds::(migrate) {'src': 'dell-r210ii-04.rhev.lab.eng.brq.redhat.com', 'dst': 'dell-r210ii-03.rhev.lab.eng.brq.redhat.com:54321', 'vmId': '2545aff1-dde2-4ce1-9de6-da6e82e8fa5c', 'method': 'online'} Thread-3079::DEBUG::2012-12-06 16:09:39,793::vm::125::vm.Vm::(_setupVdsConnection) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Destination server is: dell-r210ii-03.rhev.lab.eng.brq.redhat.com:54321 Thread-3078::DEBUG::2012-12-06 16:09:39,793::BindingXMLRPC::900::vds::(wrapper) return vmMigrate with {'status': {'message': 'Migration process starting', 'code': 0}} Thread-3079::DEBUG::2012-12-06 16:09:39,793::vm::127::vm.Vm::(_setupVdsConnection) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Initiating connection with destination Thread-3081::DEBUG::2012-12-06 16:09:40,553::BindingXMLRPC::894::vds::(wrapper) client [10.34.63.75]::call vmGetStats with ('2545aff1-dde2-4ce1-9de6-da6e82e8fa5c',) {} Thread-3081::DEBUG::2012-12-06 16:09:40,553::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3081::DEBUG::2012-12-06 16:09:40,554::BindingXMLRPC::900::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Migration Source', 'username': 'Unknown', 'memUsage': '0', 'acpiEnable': 'true', 'pid': '9243', 'displayIp': '0', 'displayPort': u'5900', 'session': 'Unknown', 'displaySecurePort': u'5901', 'timeOffset': '-1', 'hash': '-8436048150441222498', 'pauseCode': 'NOERR', 'clientIp': '', 'kvmEnable': 'true', 'network': {u'vnet0': {'macAddr': '00:1a:4a:e0:3f:82', 'rxDropped': '0', 'rxErrors': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0', 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': '2545aff1-dde2-4ce1-9de6-da6e82e8fa5c', 'displayType': 'qxl', 'cpuUser': '0.44', 'disks': {u'vda': {'readLatency': '0', 'apparentsize': '16106127360', 'writeLatency': '5343479', 'imageID': '12d760eb-ab9a-4d23-a835-7ee826f843e2', 'flushLatency': '56494', 'readRate': '0.00', 'truesize': '4398075904', 'writeRate': '2241.69'}, u'hdc': {'flushLatency': '0', 'readLatency': '0', 'writeLatency': '0'}}, 'monitorResponse': '0', 'statsAge': '0.30', 'cpuIdle': '97.16', 'elapsedTime': '704', 'vmType': 'kvm', 'cpuSys': '2.40', 'appsList': [], 'guestIPs': '', 'nice': ''}]} Thread-3083::DEBUG::2012-12-06 16:09:42,614::BindingXMLRPC::894::vds::(wrapper) client [10.34.63.75]::call vmGetStats with ('2545aff1-dde2-4ce1-9de6-da6e82e8fa5c',) {} flowID [452cf2ea] Thread-3083::DEBUG::2012-12-06 16:09:42,615::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3083::DEBUG::2012-12-06 16:09:42,615::BindingXMLRPC::900::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Migration Source', 'username': 'Unknown', 'memUsage': '0', 'acpiEnable': 'true', 'pid': '9243', 'displayIp': '0', 'displayPort': u'5900', 'session': 'Unknown', 'displaySecurePort': u'5901', 'timeOffset': '-1', 'hash': '-8436048150441222498', 'pauseCode': 'NOERR', 'clientIp': '', 'kvmEnable': 'true', 'network': {u'vnet0': {'macAddr': '00:1a:4a:e0:3f:82', 'rxDropped': '0', 'rxErrors': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0', 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': '2545aff1-dde2-4ce1-9de6-da6e82e8fa5c', 'displayType': 'qxl', 'cpuUser': '0.44', 'disks': {u'vda': {'readLatency': '0', 'apparentsize': '16106127360', 'writeLatency': '5343479', 'imageID': '12d760eb-ab9a-4d23-a835-7ee826f843e2', 'flushLatency': '56494', 'readRate': '0.00', 'truesize': '4398075904', 'writeRate': '2241.69'}, u'hdc': {'flushLatency': '0', 'readLatency': '0', 'writeLatency': '0'}}, 'monitorResponse': '0', 'statsAge': '0.36', 'cpuIdle': '97.16', 'elapsedTime': '706', 'vmType': 'kvm', 'cpuSys': '2.40', 'appsList': [], 'guestIPs': '', 'nice': ''}]} Thread-3085::DEBUG::2012-12-06 16:09:44,674::BindingXMLRPC::894::vds::(wrapper) client [10.34.63.75]::call vmGetStats with ('2545aff1-dde2-4ce1-9de6-da6e82e8fa5c',) {} Thread-3085::DEBUG::2012-12-06 16:09:44,674::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3085::DEBUG::2012-12-06 16:09:44,674::BindingXMLRPC::900::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Migration Source', 'username': 'Unknown', 'memUsage': '0', 'acpiEnable': 'true', 'pid': '9243', 'displayIp': '0', 'displayPort': u'5900', 'session': 'Unknown', 'displaySecurePort': u'5901', 'timeOffset': '-1', 'hash': '-8436048150441222498', 'pauseCode': 'NOERR', 'clientIp': '', 'kvmEnable': 'true', 'network': {u'vnet0': {'macAddr': '00:1a:4a:e0:3f:82', 'rxDropped': '0', 'rxErrors': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0', 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': '2545aff1-dde2-4ce1-9de6-da6e82e8fa5c', 'displayType': 'qxl', 'cpuUser': '0.44', 'disks': {u'vda': {'readLatency': '0', 'apparentsize': '16106127360', 'writeLatency': '5343479', 'imageID': '12d760eb-ab9a-4d23-a835-7ee826f843e2', 'flushLatency': '56494', 'readRate': '0.00', 'truesize': '4398075904', 'writeRate': '2241.69'}, u'hdc': {'flushLatency': '0', 'readLatency': '0', 'writeLatency': '0'}}, 'monitorResponse': '0', 'statsAge': '0.42', 'cpuIdle': '97.16', 'elapsedTime': '708', 'vmType': 'kvm', 'cpuSys': '2.40', 'appsList': [], 'guestIPs': '', 'nice': ''}]} Thread-3079::DEBUG::2012-12-06 16:09:44,851::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3079::DEBUG::2012-12-06 16:09:44,936::vm::175::vm.Vm::(_prepareGuest) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::migration Process begins Thread-3079::DEBUG::2012-12-06 16:09:45,019::vm::239::vm.Vm::(run) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::migration semaphore acquired Thread-3079::DEBUG::2012-12-06 16:09:45,274::libvirtvm::454::vm.Vm::(_startUnderlyingMigration) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::starting migration to qemu+tls://dell-r210ii-03.rhev.lab.eng.brq.redhat.com/system Thread-3086::DEBUG::2012-12-06 16:09:45,275::libvirtvm::352::vm.Vm::(run) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::migration downtime thread started Thread-3087::DEBUG::2012-12-06 16:09:45,275::libvirtvm::380::vm.Vm::(run) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::starting migration monitor thread libvirtEventLoop::DEBUG::2012-12-06 16:09:46,534::libvirtvm::2683::vm.Vm::(_onLibvirtLifecycleEvent) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::event Resumed detail 1 opaque None Thread-3079::DEBUG::2012-12-06 16:09:46,577::libvirtvm::367::vm.Vm::(cancel) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::canceling migration downtime thread Thread-3079::DEBUG::2012-12-06 16:09:46,577::libvirtvm::417::vm.Vm::(stop) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::stopping migration monitor thread Thread-3086::DEBUG::2012-12-06 16:09:46,577::libvirtvm::364::vm.Vm::(run) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::migration downtime thread exiting Thread-3079::ERROR::2012-12-06 16:09:46,578::vm::181::vm.Vm::(_recover) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::internal error unable to execute QEMU command 'migrate': An undefined error has ocurred Thread-3089::DEBUG::2012-12-06 16:09:48,765::task::588::TaskManager.Task::(_updateState) Task=`d5567790-1f57-4ffb-8c16-ff746d0d9120`::moving from state init -> state preparing Thread-3089::INFO::2012-12-06 16:09:48,765::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-3089::INFO::2012-12-06 16:09:48,766::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00184011459351', 'lastCheck': '2.1', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.000970125198364', 'lastCheck': '2.1', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.000998973846436', 'lastCheck': '0.4', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00106811523438', 'lastCheck': '2.1', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.0010359287262', 'lastCheck': '0.6', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00136995315552', 'lastCheck': '1.1', 'code': 0, 'valid': True}} Thread-3089::DEBUG::2012-12-06 16:09:48,766::task::1172::TaskManager.Task::(prepare) Task=`d5567790-1f57-4ffb-8c16-ff746d0d9120`::finished: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.00184011459351', 'lastCheck': '2.1', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.000970125198364', 'lastCheck': '2.1', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.000998973846436', 'lastCheck': '0.4', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00106811523438', 'lastCheck': '2.1', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.0010359287262', 'lastCheck': '0.6', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00136995315552', 'lastCheck': '1.1', 'code': 0, 'valid': True}} Thread-3089::DEBUG::2012-12-06 16:09:48,766::task::588::TaskManager.Task::(_updateState) Task=`d5567790-1f57-4ffb-8c16-ff746d0d9120`::moving from state preparing -> state finished Thread-3089::DEBUG::2012-12-06 16:09:48,766::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-3089::DEBUG::2012-12-06 16:09:48,766::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-3089::DEBUG::2012-12-06 16:09:48,767::task::978::TaskManager.Task::(_decref) Task=`d5567790-1f57-4ffb-8c16-ff746d0d9120`::ref 0 aborting False Thread-3090::DEBUG::2012-12-06 16:09:48,789::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3079::ERROR::2012-12-06 16:09:51,776::vm::262::vm.Vm::(run) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Failed to migrate Thread-3093::DEBUG::2012-12-06 16:09:52,956::BindingXMLRPC::894::vds::(wrapper) client [10.34.63.75]::call vmGetStats with ('2545aff1-dde2-4ce1-9de6-da6e82e8fa5c',) {} Thread-3093::DEBUG::2012-12-06 16:09:52,956::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available Thread-3093::DEBUG::2012-12-06 16:09:52,956::BindingXMLRPC::900::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Up', 'username': 'Unknown', 'memUsage': '0', 'acpiEnable': 'true', 'pid': '9243', 'displayIp': '0', 'displayPort': u'5900', 'session': 'Unknown', 'displaySecurePort': u'5901', 'timeOffset': '-1', 'hash': '-8436048150441222498', 'pauseCode': 'NOERR', 'clientIp': '', 'kvmEnable': 'true', 'network': {u'vnet0': {'macAddr': '00:1a:4a:e0:3f:82', 'rxDropped': '0', 'rxErrors': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0', 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': '2545aff1-dde2-4ce1-9de6-da6e82e8fa5c', 'displayType': 'qxl', 'cpuUser': '0.80', 'disks': {u'vda': {'readLatency': '0', 'apparentsize': '16106127360', 'writeLatency': '5343479', 'imageID': '12d760eb-ab9a-4d23-a835-7ee826f843e2', 'flushLatency': '56494', 'readRate': '0.00', 'truesize': '4398075904', 'writeRate': '2241.69'}, u'hdc': {'flushLatency': '0', 'readLatency': '0', 'writeLatency': '0'}}, 'monitorResponse': '0', 'statsAge': '0.68', 'cpuIdle': '97.14', 'elapsedTime': '717', 'vmType': 'kvm', 'cpuSys': '2.06', 'appsList': [], 'guestIPs': '', 'nice': ''}]} VM Channels Listener::DEBUG::2012-12-06 16:09:57,873::vmChannels::60::vds::(_handle_timeouts) Timeout on fileno 82. Thread-3096::DEBUG::2012-12-06 16:09:59,045::task::588::TaskManager.Task::(_updateState) Task=`50828b2c-c8e9-48a6-b206-9a729ec64fc0`::moving from state init -> state preparing Thread-3096::INFO::2012-12-06 16:09:59,045::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-3096::INFO::2012-12-06 16:09:59,046::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.0022120475769', 'lastCheck': '2.3', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.00159192085266', 'lastCheck': '2.3', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.00129985809326', 'lastCheck': '0.7', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00123000144958', 'lastCheck': '2.4', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00117015838623', 'lastCheck': '0.9', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00166511535645', 'lastCheck': '1.4', 'code': 0, 'valid': True}} Thread-3096::DEBUG::2012-12-06 16:09:59,046::task::1172::TaskManager.Task::(prepare) Task=`50828b2c-c8e9-48a6-b206-9a729ec64fc0`::finished: {'a7e5f59c-2877-475b-8afc-f760ba63defb': {'delay': '0.0022120475769', 'lastCheck': '2.3', 'code': 0, 'valid': True}, 'aa6e2974-a8ed-48fc-b168-7d9fb69aad53': {'delay': '0.00159192085266', 'lastCheck': '2.3', 'code': 0, 'valid': True}, 'f586a7a5-7fb6-46b8-8ecb-3dfebdc82b54': {'delay': '0.00129985809326', 'lastCheck': '0.7', 'code': 0, 'valid': True}, '131d564c-52d1-4bba-8d60-39e889a8bc08': {'delay': '0.00123000144958', 'lastCheck': '2.4', 'code': 0, 'valid': True}, 'abd2d773-3619-456c-9d50-fdee1139bb86': {'delay': '0.00117015838623', 'lastCheck': '0.9', 'code': 0, 'valid': True}, '91078fd3-4579-4d67-ba45-2f76982e8f5d': {'delay': '0.00166511535645', 'lastCheck': '1.4', 'code': 0, 'valid': True}} Thread-3096::DEBUG::2012-12-06 16:09:59,046::task::588::TaskManager.Task::(_updateState) Task=`50828b2c-c8e9-48a6-b206-9a729ec64fc0`::moving from state preparing -> state finished Thread-3096::DEBUG::2012-12-06 16:09:59,046::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-3096::DEBUG::2012-12-06 16:09:59,046::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-3096::DEBUG::2012-12-06 16:09:59,046::task::978::TaskManager.Task::(_decref) Task=`50828b2c-c8e9-48a6-b206-9a729ec64fc0`::ref 0 aborting False Thread-3097::DEBUG::2012-12-06 16:09:59,069::libvirtvm::267::vm.Vm::(_getDiskStats) vmId=`2545aff1-dde2-4ce1-9de6-da6e82e8fa5c`::Disk hdc stats not available libvirt.log ============ 2012-12-06 07:15:09.093+0000: 29792: debug : virDomainInterfaceStats:7223 : dom=0x7fc5600b81d0, (VM: name=rhel6_ws_64bit, uuid=6931ca39-6a2e-4972-8c1d-4d4a4a64c844), path=vnet1, stats=0x7fc5bb5fc330, size=64 2012-12-06 07:15:09.097+0000: 11988: debug : virDomainInterfaceStats:7223 : dom=0x7fc59401b3c0, (VM: name=winxp_updated, uuid=c21e3426-0c01-48b8-8ff7-f6c76e918d80), path=vnet2, stats=0x7fc5b8df8330, size=64 2012-12-06 10:15:09.100+0000: 30117: debug : virDomainGetCPUStats:18676 : dom=0x7fc56000db40, (VM: name=f17, uuid=9baf6e06-3c55-41f5-ad68-10a4da6e821d), params=(nil), nparams=0, start_cpu=-1, ncpus=1, flags=0 2012-12-06 10:15:09.106+0000: 30117: debug : virDomainGetCPUStats:18676 : dom=0x7fc56000db40, (VM: name=f17, uuid=9baf6e06-3c55-41f5-ad68-10a4da6e821d), params=0x7fc58c0fd870, nparams=3, start_cpu=-1, ncpus=1, flags=0 2012-12-06 10:15:09.113+0000: 30117: debug : virDomainInterfaceStats:7223 : dom=0x7fc56000db40, (VM: name=f17, uuid=9baf6e06-3c55-41f5-ad68-10a4da6e821d), path=vnet3, stats=0x7fc59f5fc330, size=64 2012-12-06 10:15:09.586+0000: 29792: debug : virDomainInterfaceStats:7223 : dom=0x7fc5600b81d0, (VM: name=rhel6_ws_64bit, uuid=6931ca39-6a2e-4972-8c1d-4d4a4a64c844), path=vnet1, stats=0x7fc5bb5fc330, size=64 2012-12-06 10:15:09.589+0000: 11988: debug : virDomainInterfaceStats:7223 : dom=0x7fc59401b3c0, (VM: name=winxp_updated, uuid=c21e3426-0c01-48b8-8ff7-f6c76e918d80), path=vnet2, stats=0x7fc5b8df8330, size=64 2012-12-06 11:15:09.213+0000: 1834: debug : virDomainInterfaceStats:7223 : dom=0x7fc5880458c0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet3, stats=0x7fc5b97f9330, size=64 2012-12-06 11:15:09.858+0000: 11988: debug : virDomainInterfaceStats:7223 : dom=0x7fc59401b3c0, (VM: name=winxp_updated, uuid=c21e3426-0c01-48b8-8ff7-f6c76e918d80), path=vnet2, stats=0x7fc5b8df8330, size=64 2012-12-06 15:09:00.075+0000: 9250: debug : virDomainQemuMonitorCommand:78 : domain=0x7ff67c0122e0, cmd={"execute": "query-blockstats"}, result=0x7ff6a0df8a00, flags=0 2012-12-06 15:09:00.151+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:05.154+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:10.158+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:15.213+0000: 9250: debug : virDomainGetCPUStats:18676 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), params=(nil), nparams=0, start_cpu=-1, ncpus=1, flags=0 2012-12-06 15:09:15.219+0000: 9250: debug : virDomainGetCPUStats:18676 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), params=0x7ff68c013fc0, nparams=3, start_cpu=-1, ncpus=1, flags=0 2012-12-06 15:09:15.224+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:20.227+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:25.230+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:30.234+0000: 9250: debug : virDomainGetCPUStats:18676 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), params=(nil), nparams=0, start_cpu=-1, ncpus=1, flags=0 2012-12-06 15:09:30.240+0000: 9250: debug : virDomainGetCPUStats:18676 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), params=0x7ff68c011550, nparams=3, start_cpu=-1, ncpus=1, flags=0 2012-12-06 15:09:30.245+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:35.248+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:40.251+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:44.851+0000: 10143: debug : virDomainGetXMLDesc:4379 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), flags=0 2012-12-06 15:09:44.940+0000: 10143: debug : virDomainGetXMLDesc:4379 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), flags=0 2012-12-06 15:09:45.022+0000: 10143: debug : virDomainGetXMLDesc:4379 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), flags=0 2012-12-06 15:09:45.094+0000: 10143: debug : virDomainGetXMLDesc:4379 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), flags=0 2012-12-06 15:09:45.255+0000: 9250: debug : virDomainGetCPUStats:18676 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), params=(nil), nparams=0, start_cpu=-1, ncpus=1, flags=0 2012-12-06 15:09:45.260+0000: 9250: debug : virDomainGetCPUStats:18676 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), params=0x7ff68c0111f0, nparams=3, start_cpu=-1, ncpus=1, flags=0 2012-12-06 15:09:45.266+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:45.275+0000: 10143: debug : virDomainMigrateToURI2:5710 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), dconnuri=qemu+tls://dell-r210ii-03.rhev.lab.eng.brq.redhat.com/system, miguri=tcp://dell-r210ii-03.rhev.lab.eng.brq.redhat.com, dxml=(null), flags=3, dname=(null), bandwidth=0 2012-12-06 15:09:45.278+0000: 10143: debug : virDomainMigrateToURI2:5728 : Using peer2peer migration 2012-12-06 15:09:45.278+0000: 10143: debug : virDomainMigratePeer2Peer:4969 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), xmlin=(null), flags=3, dname=(null), dconnuri=qemu+tls://dell-r210ii-03.rhev.lab.eng.brq.redhat.com/system, uri=tcp://dell-r210ii-03.rhev.lab.eng.brq.redhat.com, bandwidth=0 2012-12-06 15:09:45.281+0000: 10143: debug : virDomainMigratePeer2Peer:4997 : Using migration protocol 3 2012-12-06 15:09:46.534+0000: 10143: debug : virDomainFree:2313 : dom=0x7ff6800f5170, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c) 2012-12-06 15:09:46.534+0000: 2711: debug : virDomainRef:2355 : dom=0x7ff700003f60, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), refs=1 2012-12-06 15:09:46.534+0000: 2711: debug : virDomainGetUUIDString:3442 : dom=0x7ff700003f60, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), buf=0x7ff708593090 2012-12-06 15:09:46.534+0000: 2711: debug : virDomainGetUUID:3407 : dom=0x7ff700003f60, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), uuid=0x7ff708593040 2012-12-06 15:09:46.535+0000: 2711: debug : virDomainFree:2313 : dom=0x7ff700003f60, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c) 2012-12-06 15:09:46.535+0000: 2711: debug : virDomainFree:2313 : dom=0x7ff700003f60, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c) 2012-12-06 15:09:46.577+0000: 10143: error : virNetClientProgramDispatchError:174 : internal error unable to execute QEMU command 'migrate': An undefined error has ocurred 2012-12-06 15:09:46.578+0000: 10152: debug : virDomainGetJobInfo:16400 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), info=0x7ff6a3ffdd70 2012-12-06 15:09:50.272+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 2012-12-06 15:09:51.669+0000: 10143: debug : virDomainGetXMLDesc:4379 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), flags=0 2012-12-06 15:09:55.276+0000: 9250: debug : virDomainInterfaceStats:7223 : dom=0x7ff67c0122e0, (VM: name=rhel6_ws_32bit, uuid=2545aff1-dde2-4ce1-9de6-da6e82e8fa5c), path=vnet0, stats=0x7ff6a0df8330, size=64 dumpxml ======= <domain type='kvm' id='8'> <name>rhel6_ws_32bit</name> <uuid>2545aff1-dde2-4ce1-9de6-da6e82e8fa5c</uuid> <memory unit='KiB'>1048576</memory> <currentMemory unit='KiB'>1048576</currentMemory> <vcpu placement='static'>2</vcpu> <cputune> <shares>1020</shares> </cputune> <sysinfo type='smbios'> <system> <entry name='manufacturer'>Red Hat</entry> <entry name='product'>RHEV Hypervisor</entry> <entry name='version'>6Server-6.3.0.3.el6</entry> <entry name='serial'>4C4C4544-0058-3410-8058-C2C04F38354A_D0:67:E5:EE:65:09</entry> <entry name='uuid'>2545aff1-dde2-4ce1-9de6-da6e82e8fa5c</entry> </system> </sysinfo> <os> <type arch='x86_64' machine='rhel6.3.0'>hvm</type> <boot dev='hd'/> <smbios mode='sysinfo'/> </os> <features> <acpi/> </features> <cpu mode='custom' match='exact'> <model fallback='allow'>Conroe</model> <topology sockets='2' cores='1' threads='1'/> </cpu> <clock offset='variable' adjustment='-1'> <timer name='rtc' tickpolicy='catchup'/> </clock> <on_poweroff>destroy</on_poweroff> <on_reboot>restart</on_reboot> <on_crash>destroy</on_crash> <devices> <emulator>/usr/libexec/qemu-kvm</emulator> <disk type='file' device='cdrom'> <driver name='qemu' type='raw'/> <source startupPolicy='optional'/> <target dev='hdc' bus='ide'/> <readonly/> <serial></serial> <alias name='ide0-1-0'/> <address type='drive' controller='0' bus='1' target='0' unit='0'/> </disk> <disk type='file' device='disk' snapshot='no'> <driver name='qemu' type='raw' cache='none' error_policy='stop' io='threads'/> <source file='/rhev/data-center/08d10f90-3257-11e2-a035-001a4a013f3c/aa6e2974-a8ed-48fc-b168-7d9fb69aad53/images/12d760eb-ab9a-4d23-a835-7ee826f843e2/b8d92c04-9115-4e9b-a12c-226f87b2dfba'> <seclabel relabel='no'/> </source> <target dev='vda' bus='virtio'/> <serial>12d760eb-ab9a-4d23-a835-7ee826f843e2</serial> <alias name='virtio-disk0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/> </disk> <controller type='usb' index='0' model='ich9-ehci1'> <alias name='usb0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x7'/> </controller> <controller type='usb' index='0' model='ich9-uhci1'> <alias name='usb0'/> <master startport='0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0' multifunction='on'/> </controller> <controller type='usb' index='0' model='ich9-uhci2'> <alias name='usb0'/> <master startport='2'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x1'/> </controller> <controller type='usb' index='0' model='ich9-uhci3'> <alias name='usb0'/> <master startport='4'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x2'/> </controller> <controller type='ide' index='0'> <alias name='ide0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x1'/> </controller> <controller type='virtio-serial' index='0'> <alias name='virtio-serial0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x07' function='0x0'/> </controller> <interface type='bridge'> <mac address='00:1a:4a:e0:3f:82'/> <source bridge='rhevm'/> <target dev='vnet0'/> <model type='virtio'/> <filterref filter='vdsm-no-mac-spoofing'/> <alias name='net0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/> </interface> <channel type='unix'> <source mode='bind' path='/var/lib/libvirt/qemu/channels/rhel6_ws_32bit.com.redhat.rhevm.vdsm'/> <target type='virtio' name='com.redhat.rhevm.vdsm'/> <alias name='channel0'/> <address type='virtio-serial' controller='0' bus='0' port='1'/> </channel> <channel type='unix'> <source mode='bind' path='/var/lib/libvirt/qemu/channels/rhel6_ws_32bit.org.qemu.guest_agent.0'/> <target type='virtio' name='org.qemu.guest_agent.0'/> <alias name='channel1'/> <address type='virtio-serial' controller='0' bus='0' port='2'/> </channel> <channel type='spicevmc'> <target type='virtio' name='com.redhat.spice.0'/> <alias name='channel2'/> <address type='virtio-serial' controller='0' bus='0' port='3'/> </channel> <input type='mouse' bus='ps2'/> <graphics type='spice' port='5900' tlsPort='5901' autoport='yes' listen='0' keymap='en-us' passwdValidTo='1970-01-01T00:00:01'> <listen type='address' address='0'/> <channel name='main' mode='secure'/> <channel name='display' mode='secure'/> <channel name='inputs' mode='secure'/> <channel name='cursor' mode='secure'/> <channel name='playback' mode='secure'/> <channel name='record' mode='secure'/> <channel name='smartcard' mode='secure'/> <channel name='usbredir' mode='secure'/> </graphics> <sound model='ich6'> <alias name='sound0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/> </sound> <video> <model type='qxl' vram='65536' heads='1'/> <alias name='video0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/> </video> <redirdev bus='usb' type='spicevmc'> <alias name='redir0'/> </redirdev> <redirdev bus='usb' type='spicevmc'> <alias name='redir1'/> </redirdev> <redirdev bus='usb' type='spicevmc'> <alias name='redir2'/> </redirdev> <redirdev bus='usb' type='spicevmc'> <alias name='redir3'/> </redirdev> <memballoon model='virtio'> <alias name='balloon0'/> <address type='pci' domain='0x0000' bus='0x00' slot='0x08' function='0x0'/> </memballoon> </devices> <seclabel type='dynamic' model='selinux' relabel='yes'> <label>system_u:system_r:svirt_t:s0:c156,c605</label> <imagelabel>system_u:object_r:svirt_image_t:s0:c156,c605</imagelabel> </seclabel> </domain>