Hi all,
Hi have one computer hosting several VM, this particular server is
in need of maintenance and has to be shutdown.
In order to avoid disrupting the services provided by the VM I
intended to migrate the VM to another computer.
Computer 1 and 2 do not share any storage. So it is necessary to
migrate not only the memory but also any data on the hard-drive.
Both computers are running debian squeeze.
Virsh is version 0.8.3.
I issue this command on server one:
sudo LIBVIRT_DEBUG=1 virsh migrate --live --copy-storage-all
i00cn1011 qemu+ssh://user@computer2/session > debug.log
2>&1
On virt-manager on computer 1, the VM appears for a few moments as
paused, and then disappears.
On computer 1 I receive the error: Timed out during operation:
cannot acquire state change lock
Does anyone know what the problem may be and how to solve it?
Next I send all the data returned by virsh.
Thanks everyone.
user@computer1:~$ cat debug.log
13:52:07.911: debug : virInitialize:339 : register drivers
13:52:07.911: debug : virRegisterDriver:927 : registering Test as
driver 0
13:52:07.911: debug : virRegisterNetworkDriver:733 : registering
Test as network driver 0
13:52:07.911: debug : virRegisterInterfaceDriver:764 : registering
Test as interface driver 0
13:52:07.911: debug : virRegisterStorageDriver:795 : registering
Test as storage driver 0
13:52:07.911: debug : virRegisterDeviceMonitor:826 : registering
Test as device driver 0
13:52:07.911: debug : virRegisterSecretDriver:857 : registering
Test as secret driver 0
13:52:07.911: debug : virRegisterNWFilterDriver:888 : registering
Test as network filter driver 0
13:52:07.911: debug : virRegisterDriver:927 : registering Xen as
driver 1
13:52:07.911: debug : virRegisterDriver:927 : registering OPENVZ
as driver 2
13:52:07.911: debug : vboxRegister:122 : VBoxCGlueInit failed,
using dummy driver
13:52:07.911: debug : virRegisterDriver:927 : registering VBOX as
driver 3
13:52:07.911: debug : virRegisterNetworkDriver:733 : registering
VBOX as network driver 1
13:52:07.911: debug : virRegisterStorageDriver:795 : registering
VBOX as storage driver 1
13:52:07.911: debug : virRegisterDriver:927 : registering remote
as driver 4
13:52:07.911: debug : virRegisterNetworkDriver:733 : registering
remote as network driver 2
13:52:07.911: debug : virRegisterInterfaceDriver:764 : registering
remote as interface driver 1
13:52:07.911: debug : virRegisterStorageDriver:795 : registering
remote as storage driver 2
13:52:07.911: debug : virRegisterDeviceMonitor:826 : registering
remote as device driver 1
13:52:07.911: debug : virRegisterSecretDriver:857 : registering
remote as secret driver 1
13:52:07.911: debug : virRegisterNWFilterDriver:888 : registering
remote as network filter driver 1
13:52:07.911: debug : virConnectOpenAuth:1498 : name=(null),
auth=0x7f3c96c6c7a0, flags=0
13:52:07.911: debug : do_open:1206 : no name, allowing driver
auto-select
13:52:07.911: debug : do_open:1243 : trying driver 0 (Test) ...
13:52:07.911: debug : do_open:1249 : driver 0 Test returned
DECLINED
13:52:07.911: debug : do_open:1243 : trying driver 1 (Xen) ...
13:52:07.911: debug : do_open:1249 : driver 1 Xen returned
DECLINED
13:52:07.911: debug : do_open:1243 : trying driver 2 (OPENVZ) ...
13:52:07.911: debug : do_open:1249 : driver 2 OPENVZ returned
DECLINED
13:52:07.911: debug : do_open:1243 : trying driver 3 (VBOX) ...
13:52:07.911: debug : do_open:1249 : driver 3 VBOX returned
DECLINED
13:52:07.911: debug : do_open:1243 : trying driver 4 (remote) ...
13:52:07.911: debug : remoteOpen:1120 : Auto-probe remote URI
13:52:07.911: debug : doRemoteOpen:564 : proceeding with name =
13:52:07.911: debug : remoteIO:9886 : Do proc=66 serial=0
length=28 wait=(nil)
13:52:07.911: debug : remoteIO:9961 : We have the buck 66
0x7f3c96d01010 0x7f3c96d01010
13:52:07.912: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 64 total (60 more)
13:52:07.912: debug : remoteIOEventLoop:9812 : Giving up the buck
66 0x7f3c96d01010 (nil)
13:52:07.912: debug : remoteIO:9990 : All done with our call 66
(nil) 0x7f3c96d01010
13:52:07.912: debug : remoteIO:9886 : Do proc=1 serial=1 length=40
wait=(nil)
13:52:07.912: debug : remoteIO:9961 : We have the buck 1 0xe671b0
0xe671b0
13:52:07.912: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 56 total (52 more)
13:52:07.912: debug : remoteIOEventLoop:9812 : Giving up the buck
1 0xe671b0 (nil)
13:52:07.912: debug : remoteIO:9990 : All done with our call 1
(nil) 0xe671b0
13:52:07.912: debug : remoteIO:9886 : Do proc=110 serial=2
length=28 wait=(nil)
13:52:07.912: debug : remoteIO:9961 : We have the buck 110
0xe671b0 0xe671b0
13:52:07.913: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 76 total (72 more)
13:52:07.913: debug : remoteIOEventLoop:9812 : Giving up the buck
110 0xe671b0 (nil)
13:52:07.913: debug : remoteIO:9990 : All done with our call 110
(nil) 0xe671b0
13:52:07.913: debug : doRemoteOpen:922 : Auto-probed URI is
qemu:///system
13:52:07.913: debug : doRemoteOpen:941 : Adding Handler for remote
events
13:52:07.913: debug : doRemoteOpen:948 : virEventAddHandle failed:
No addHandleImpl defined. continuing without events.
13:52:07.913: debug : do_open:1249 : driver 4 remote returned
SUCCESS
13:52:07.913: debug : do_open:1269 : network driver 0 Test
returned DECLINED
13:52:07.913: debug : do_open:1269 : network driver 1 VBOX
returned DECLINED
13:52:07.913: debug : do_open:1269 : network driver 2 remote
returned SUCCESS
13:52:07.913: debug : do_open:1288 : interface driver 0 Test
returned DECLINED
13:52:07.913: debug : do_open:1288 : interface driver 1 remote
returned SUCCESS
13:52:07.913: debug : do_open:1308 : storage driver 0 Test
returned DECLINED
13:52:07.913: debug : do_open:1308 : storage driver 1 VBOX
returned DECLINED
13:52:07.913: debug : do_open:1308 : storage driver 2 remote
returned SUCCESS
13:52:07.913: debug : do_open:1328 : node driver 0 Test returned
DECLINED
13:52:07.913: debug : do_open:1328 : node driver 1 remote returned
SUCCESS
13:52:07.913: debug : do_open:1355 : secret driver 0 Test returned
DECLINED
13:52:07.913: debug : do_open:1355 : secret driver 1 remote
returned SUCCESS
13:52:07.913: debug : do_open:1375 : nwfilter driver 0 Test
returned DECLINED
13:52:07.913: debug : do_open:1375 : nwfilter driver 1 remote
returned SUCCESS
13:52:07.913: debug : virDomainLookupByName:2154 : conn=0xe61390,
name=i00cn1011
13:52:07.913: debug : remoteIO:9886 : Do proc=23 serial=3
length=44 wait=(nil)
13:52:07.913: debug : remoteIO:9961 : We have the buck 23 0xe671b0
0xe671b0
13:52:07.913: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 92 total (88 more)
13:52:07.913: debug : remoteIOEventLoop:9812 : Giving up the buck
23 0xe671b0 (nil)
13:52:07.913: debug : remoteIO:9990 : All done with our call 23
(nil) 0xe671b0
13:52:07.913: debug : virGetDomain:382 : New hash entry 0xe5da00
13:52:07.913: debug : virConnectOpenAuth:1498 :
name=qemu+ssh://user@computer2/session, auth=0x7f3c96c6c7a0,
flags=0
13:52:07.913: debug : do_open:1204 : name
"qemu+ssh://user@computer2/session" to URI components:
scheme qemu+ssh
opaque (null)
authority (null)
server computer2
user user
port 0
path /session
13:52:07.913: debug : do_open:1243 : trying driver 0 (Test) ...
13:52:07.913: debug : do_open:1249 : driver 0 Test returned
DECLINED
13:52:07.913: debug : do_open:1243 : trying driver 1 (Xen) ...
13:52:07.913: debug : do_open:1249 : driver 1 Xen returned
DECLINED
13:52:07.913: debug : do_open:1243 : trying driver 2 (OPENVZ) ...
13:52:07.913: debug : do_open:1249 : driver 2 OPENVZ returned
DECLINED
13:52:07.913: debug : do_open:1243 : trying driver 3 (VBOX) ...
13:52:07.913: debug : do_open:1249 : driver 3 VBOX returned
DECLINED
13:52:07.913: debug : do_open:1243 : trying driver 4 (remote) ...
13:52:07.913: debug : doRemoteOpen:564 : proceeding with name =
qemu:///session
13:52:07.914: debug : virExecWithHook:712 : ssh -l user computer2
sh -c 'nc -q 2>&1 | grep -q "requires an argument";if [ $?
-eq 0 ] ; then CMD="nc -q 0 -U
/var/run/libvirt/libvirt-sock";else CMD="nc -U
/var/run/libvirt/libvirt-sock";fi;eval "$CMD";'
13:52:07.914: debug : remoteIO:9886 : Do proc=66 serial=0
length=28 wait=(nil)
13:52:07.914: debug : remoteIO:9961 : We have the buck 66 0xeaabd0
0xeaabd0
13:52:08.006: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 36 total (32 more)
13:52:08.006: debug : remoteIOEventLoop:9812 : Giving up the buck
66 0xeaabd0 (nil)
13:52:08.006: debug : remoteIO:9990 : All done with our call 66
(nil) 0xeaabd0
13:52:08.006: debug : remoteIO:9886 : Do proc=1 serial=1 length=56
wait=(nil)
13:52:08.006: debug : remoteIO:9961 : We have the buck 1 0xeaabd0
0xeaabd0
13:52:08.007: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 28 total (24 more)
13:52:08.007: debug : remoteIOEventLoop:9812 : Giving up the buck
1 0xeaabd0 (nil)
13:52:08.007: debug : remoteIO:9990 : All done with our call 1
(nil) 0xeaabd0
13:52:08.007: debug : doRemoteOpen:941 : Adding Handler for remote
events
13:52:08.007: debug : doRemoteOpen:948 : virEventAddHandle failed:
No addHandleImpl defined. continuing without events.
13:52:08.007: debug : do_open:1249 : driver 4 remote returned
SUCCESS
13:52:08.007: debug : do_open:1269 : network driver 0 Test
returned DECLINED
13:52:08.007: debug : do_open:1269 : network driver 1 VBOX
returned DECLINED
13:52:08.007: debug : do_open:1269 : network driver 2 remote
returned SUCCESS
13:52:08.007: debug : do_open:1288 : interface driver 0 Test
returned DECLINED
13:52:08.007: debug : do_open:1288 : interface driver 1 remote
returned SUCCESS
13:52:08.007: debug : do_open:1308 : storage driver 0 Test
returned DECLINED
13:52:08.007: debug : do_open:1308 : storage driver 1 VBOX
returned DECLINED
13:52:08.007: debug : do_open:1308 : storage driver 2 remote
returned SUCCESS
13:52:08.007: debug : do_open:1328 : node driver 0 Test returned
DECLINED
13:52:08.007: debug : do_open:1328 : node driver 1 remote returned
SUCCESS
13:52:08.007: debug : do_open:1355 : secret driver 0 Test returned
DECLINED
13:52:08.007: debug : do_open:1355 : secret driver 1 remote
returned SUCCESS
13:52:08.007: debug : do_open:1375 : nwfilter driver 0 Test
returned DECLINED
13:52:08.007: debug : do_open:1375 : nwfilter driver 1 remote
returned SUCCESS
13:52:08.007: debug : virDomainMigrate:3517 : domain=0xe5da00,
dconn=0xe62b00, flags=65, dname=(null), uri=(null), bandwidth=0
13:52:08.008: debug : remoteIO:9886 : Do proc=60 serial=4
length=32 wait=(nil)
13:52:08.008: debug : remoteIO:9961 : We have the buck 60 0xeaac10
0xeaac10
13:52:08.008: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 60 total (56 more)
13:52:08.008: debug : remoteIOEventLoop:9812 : Giving up the buck
60 0xeaac10 (nil)
13:52:08.008: debug : remoteIO:9990 : All done with our call 60
(nil) 0xeaac10
13:52:08.008: debug : remoteIO:9886 : Do proc=60 serial=5
length=32 wait=(nil)
13:52:08.008: debug : remoteIO:9961 : We have the buck 60 0xeaac10
0xeaac10
13:52:08.008: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 60 total (56 more)
13:52:08.008: debug : remoteIOEventLoop:9812 : Giving up the buck
60 0xeaac10 (nil)
13:52:08.008: debug : remoteIO:9990 : All done with our call 60
(nil) 0xeaac10
13:52:08.008: debug : remoteIO:9886 : Do proc=60 serial=2
length=32 wait=(nil)
13:52:08.008: debug : remoteIO:9961 : We have the buck 60 0xeaac10
0xeaac10
13:52:08.009: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 32 total (28 more)
13:52:08.009: debug : remoteIOEventLoop:9812 : Giving up the buck
60 0xeaac10 (nil)
13:52:08.009: debug : remoteIO:9990 : All done with our call 60
(nil) 0xeaac10
13:52:08.009: debug : remoteIO:9886 : Do proc=14 serial=6
length=68 wait=(nil)
13:52:08.009: debug : remoteIO:9961 : We have the buck 14 0xeaac10
0xeaac10
13:52:08.009: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 2540 total (2536 more)
13:52:08.009: debug : remoteIOEventLoop:9812 : Giving up the buck
14 0xeaac10 (nil)
13:52:08.010: debug : remoteIO:9990 : All done with our call 14
(nil) 0xeaac10
13:52:08.010: debug : virDomainGetInfo:3017 : domain=0xe5da00,
info=0x7fff102893e0
13:52:08.010: debug : remoteIO:9886 : Do proc=16 serial=7
length=64 wait=(nil)
13:52:08.010: debug : remoteIO:9961 : We have the buck 16 0xeaac10
0xeaac10
13:52:08.010: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 88 total (84 more)
13:52:08.010: debug : remoteIOEventLoop:9812 : Giving up the buck
16 0xeaac10 (nil)
13:52:08.010: debug : remoteIO:9990 : All done with our call 16
(nil) 0xeaac10
13:52:08.010: debug : remoteIO:9886 : Do proc=108 serial=3
length=2536 wait=(nil)
13:52:08.010: debug : remoteIO:9961 : We have the buck 108
0xeaac10 0xeaac10
13:52:08.291: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 68 total (64 more)
13:52:08.291: debug : remoteIOEventLoop:9812 : Giving up the buck
108 0xeaac10 (nil)
13:52:08.291: debug : remoteIO:9990 : All done with our call 108
(nil) 0xeaac10
13:52:08.291: debug : remoteIO:9886 : Do proc=62 serial=8
length=120 wait=(nil)
13:52:08.291: debug : remoteIO:9961 : We have the buck 62 0xeaac10
0xeaac10
13:52:38.000: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 208 total (204 more)
13:52:38.000: debug : remoteIOEventLoop:9812 : Giving up the buck
62 0xeaac10 (nil)
13:52:38.000: debug : remoteIO:9990 : All done with our call 62
(nil) 0xeaac10
13:52:38.000: debug : remoteIO:9886 : Do proc=109 serial=4
length=92 wait=(nil)
13:52:38.000: debug : remoteIO:9961 : We have the buck 109
0xeaac10 0xeaac10
13:52:38.211: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 120 total (116 more)
13:52:38.211: debug : remoteIOEventLoop:9812 : Giving up the buck
109 0xeaac10 (nil)
13:52:38.211: debug : remoteIO:9990 : All done with our call 109
(nil) 0xeaac10
13:52:38.211: debug : virConnectClose:1524 : conn=0xe62b00
13:52:38.211: debug : virUnrefConnect:294 : unref connection
0xe62b00 1
13:52:38.211: debug : remoteIO:9886 : Do proc=2 serial=5 length=28
wait=(nil)
13:52:38.211: debug : remoteIO:9961 : We have the buck 2 0xeaac10
0xeaac10
13:52:38.212: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 28 total (24 more)
13:52:38.212: debug : remoteIOEventLoop:9812 : Giving up the buck
2 0xeaac10 (nil)
13:52:38.212: debug : remoteIO:9990 : All done with our call 2
(nil) 0xeaac10
13:52:38.212: debug : virReleaseConnect:249 : release connection
0xe62b00
13:52:38.212: debug : virDomainFree:2242 : domain=0xe5da00
13:52:38.212: debug : virUnrefDomain:463 : unref domain 0xe5da00
i00cn1011 1
13:52:38.212: debug : virReleaseDomain:416 : release domain
0xe5da00 i00cn1011 4dd247bc-533a-db0d-f1e5-f1310169e62f
13:52:38.213: debug : virReleaseDomain:433 : unref connection
0xe61390 2
error: Timed out during operation: cannot acquire state change
lock
13:52:38.213: debug : virConnectClose:1524 : conn=0xe61390
13:52:38.213: debug : virUnrefConnect:294 : unref connection
0xe61390 1
13:52:38.213: debug : remoteIO:9886 : Do proc=2 serial=9 length=28
wait=(nil)
13:52:38.213: debug : remoteIO:9961 : We have the buck 2 0xe671b0
0xe671b0
13:52:38.213: debug : remoteIODecodeMessageLength:9314 : Got
length, now need 56 total (52 more)
13:52:38.213: debug : remoteIOEventLoop:9812 : Giving up the buck
2 0xe671b0 (nil)
13:52:38.213: debug : remoteIO:9990 : All done with our call 2
(nil) 0xe671b0
13:52:38.213: debug : virReleaseConnect:249 : release connection
0xe61390