[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]

[libvirt-users] virsh migrate results in error: Timed out during operation: cannot acquire state change lock



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

[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]