Bug 861792

Summary:	When attempting to migrate a guest VM, target host cant find domain
Product:	[Community] Virtualization Tools	Reporter:	Shawn Starr <shawn.starr>
Component:	libvirt	Assignee:	Libvirt Maintainers <libvirt-maint>
Status:	CLOSED INSUFFICIENT_DATA	QA Contact:
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	unspecified	CC:	acathrow
Target Milestone:	---
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2014-04-22 14:47:20 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Shawn Starr 2012-09-30 19:20:36 UTC

Description of problem:

If attempting to migrate a VM from one host to another, it fails unless a 2nd attempt is done.


Note: This happens with both tunnelled over libvirtd or without tunneling

1) No TLS (no encryption) enabled, TCP enabled

Version-Release number of selected component (if applicable):
libvirt-XXXXXXXXXXX-0.10.2-3.fc19.x86_64

How reproducible: 100%

Steps to Reproduce:
1. Attempt to migrate VM to another host
2. Fails saying domain cannot be found
3. Attempt to migrate the VM again, this time it is successful
  
Actual results:
Fails first time

Expected results:

Should not require migration 2 times.

Comment 1 Shawn Starr 2012-09-30 19:22:13 UTC

Problems live migrating a Windows VM - Inconsistent?
From:	Shawn Starr <shawn.starr@XXXXXXXX>  (sh0n.net)
To:	libvir-list@XXXXXXXXXXX
Date:	Today 02:20:37 PM
Hello, 

I noticed some issues migrating a VM

1) I had to have ssh key authentication exchanged or it would refuse to 
connect tunneled to the remote libvirtd server

2) When it attempts to finish live migrating the VM it fails saying it can't 
find the domain on the remote libvirtd server host

However, if I run the command again to migrate, it DOES migrate the VM over.

Versions:

host kernel: 3.6.0-0.rc7.git0.1.fc18.x86_64
libvirt-XXXXXXX-0.10.2-3.fc18.x86_64
qemu-kvm-1.2.0-8.fc18.x86_64  (will upgrade to latest on koji but unrelated I believe)

Command:

LIBVIRT_DEBUG=1 virsh --debug=4 migrate --verbose --live --tunnelled --p2p Windows qemu+ssh://root.2.3/system

Output:

...
<snip>

2012-09-30 17:59:14.814+0000: 24710: debug : virKeepAliveCheckMessage:384 : ka=0x266a470, client=0x2669ee0, msg=0x2669f48
2012-09-30 17:59:14.814+0000: 24710: debug : virNetClientIOEventLoopRemoveDone:1380 : Waking up sleep 0x2669cb0
2012-09-30 17:59:14.814+0000: 24708: debug : virNetClientIO:1754 : Woken up from sleep head=0x7f4830400e60 call=0x2669cb0
2012-09-30 17:59:14.814+0000: 24708: debug : virNetClientIO:1807 : All done with our call head=0x7f4830400e60 call=0x2669cb0 rv=0
2012-09-30 17:59:14.814+0000: 24708: debug : virNetMessageFree:73 : msg=0x2669640 nfds=0 cb=(nil)
Migration: [ 95 %]2012-09-30 17:59:15.315+0000: 24708: debug : virDomainGetJobInfo:17129 : dom=0x2669e70, (VM: name=Windows, uuid=41562d70-d0a8-25bc-10ec-a3dc46b3d258), info=0x7fffb64d72d0
2012-09-30 17:59:15.315+0000: 24708: debug : virNetMessageNew:45 : msg=0x2669640 tracked=0
2012-09-30 17:59:15.315+0000: 24708: debug : virNetMessageEncodePayload:358 : Encode length as 64
2012-09-30 17:59:15.315+0000: 24708: debug : virNetClientSendInternal:1955 : RPC_CLIENT_MSG_TX_QUEUE: client=0x2669ee0 len=64 prog=536903814 vers=1 proc=163 type=0 status=0 serial=50
2012-09-30 17:59:15.315+0000: 24708: debug : virNetClientCallNew:1908 : New call 0x2669150: msg=0x2669640, expectReply=1, nonBlock=0
2012-09-30 17:59:15.315+0000: 24708: debug : virNetClientIO:1718 : Outgoing message prog=536903814 version=1 serial=50 proc=163 type=0 length=64 dispatch=0x7f4830400e60
2012-09-30 17:59:15.315+0000: 24708: debug : virNetClientIO:1744 : Going to sleep head=0x7f4830400e60 call=0x2669150
2012-09-30 17:59:15.315+0000: 24710: debug : virNetClientIOEventLoop:1558 : Woken up from poll by other thread
2012-09-30 17:59:15.317+0000: 24710: debug : virNetMessageDecodeLength:152 : Got length, now need 120 total (116 more)
2012-09-30 17:59:15.317+0000: 24710: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x2669ee0 len=120 prog=536903814 vers=1 proc=163 type=1 status=0 serial=50
2012-09-30 17:59:15.317+0000: 24710: debug : virKeepAliveCheckMessage:384 : ka=0x266a470, client=0x2669ee0, msg=0x2669f48
2012-09-30 17:59:15.317+0000: 24710: debug : virNetClientIOEventLoopRemoveDone:1380 : Waking up sleep 0x2669150
2012-09-30 17:59:15.317+0000: 24708: debug : virNetClientIO:1754 : Woken up from sleep head=0x7f4830400e60 call=0x2669150
2012-09-30 17:59:15.317+0000: 24708: debug : virNetClientIO:1807 : All done with our call head=0x7f4830400e60 call=0x2669150 rv=0
2012-09-30 17:59:15.317+0000: 24708: debug : virNetMessageFree:73 : msg=0x2669640 nfds=0 cb=(nil)
Migration: [ 95 %]2012-09-30 17:59:15.751+0000: 24710: debug : virNetMessageDecodeLength:152 : Got length, now need 204 total (200 more)
2012-09-30 17:59:15.751+0000: 24710: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x2669ee0 len=204 prog=536903814 vers=1 proc=216 type=1 status=1 serial=8
2012-09-30 17:59:15.751+0000: 24710: debug : virKeepAliveCheckMessage:384 : ka=0x266a470, client=0x2669ee0, msg=0x2669f48
2012-09-30 17:59:15.751+0000: 24710: debug : virNetClientIOEventLoopPassTheBuck:1424 : Giving up the buck 0x7f4830400e60
2012-09-30 17:59:15.751+0000: 24710: debug : virNetClientIOEventLoopPassTheBuck:1438 : No thread to pass the buck to
2012-09-30 17:59:15.751+0000: 24710: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2012-09-30 17:59:15.751+0000: 24710: debug : virEventPollInterruptLocked:701 : Interrupting
2012-09-30 17:59:15.751+0000: 24710: debug : virNetClientIO:1807 : All done with our call head=(nil) call=0x7f4830400e60 rv=0
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollDispatchHandles:455 : Dispatch 1
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollDispatchHandles:469 : i=0 w=1
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollCleanupHandles:549 : Cleanup 2
2012-09-30 17:59:15.751+0000: 24709: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollCleanupHandles:549 : Cleanup 2
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=1 d=0
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
2012-09-30 17:59:15.751+0000: 24709: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=2 timeout=-1
2012-09-30 17:59:15.751+0000: 24710: debug : virNetMessageFree:73 : msg=0x7f4830000de0 nfds=0 cb=(nil)
2012-09-30 17:59:15.751+0000: 24710: debug : virDomainFree:2281 : dom=0x7f4830000af0, (VM: name=Windows, uuid=41562d70-d0a8-25bc-10ec-a3dc46b3d258)
2012-09-30 17:59:15.751+0000: 24710: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7f4830000af0
2012-09-30 17:59:15.751+0000: 24710: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0x7f4830000af0
2012-09-30 17:59:15.751+0000: 24710: debug : virDomainDispose:225 : release domain 0x7f4830000af0 Windows 41562d70-d0a8-25bc-10ec-a3dc46b3d258
2012-09-30 17:59:15.751+0000: 24710: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x26693b0
2012-09-30 17:59:15.751+0000: 24708: debug : virDomainFree:2281 : dom=0x2669e70, (VM: name=Windows, uuid=41562d70-d0a8-25bc-10ec-a3dc46b3d258)
2012-09-30 17:59:15.751+0000: 24708: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x2669e70
2012-09-30 17:59:15.751+0000: 24708: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0x2669e70
2012-09-30 17:59:15.751+0000: 24708: debug : virDomainDispose:225 : release domain 0x2669e70 Windows 41562d70-d0a8-25bc-10ec-a3dc46b3d258
2012-09-30 17:59:15.752+0000: 24708: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x26693b0
2012-09-30 17:59:15.752+0000: 24708: debug : virFileClose:72 : Closed fd 9
2012-09-30 17:59:15.752+0000: 24708: debug : virFileClose:72 : Closed fd 10
error: Domain not found: no domain with matching name 'Windows'

Comment 2 Shawn Starr 2012-09-30 19:31:03 UTC

When using virt-manager:

Unable to migrate guest: Requested operation is not valid: domain 'Windows' is not processing incoming migration

Again, 2nd time this will be successful

Comment 3 Shawn Starr 2014-04-22 14:47:20 UTC

Close this, if it happens again Spin a new ticket.