Attachment 599536 Details for Bug 842068 – Output from LIBVIRT_DEBUG=1

Output from LIBVIRT_DEBUG=1

libvirt-debug.log (text/plain), 45.88 KB, created by Richard W.M. Jones on 2012-07-21 16:00:43 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Richard W.M. Jones

Created: 2012-07-21 16:00:43 UTC

Size: 45.88 KB

patch

obsolete

>2012-07-21 16:00:11.497+0000: 6042: info : libvirt version: 0.9.13, package: 1.fc18 (Fedora Project, 2012-07-02-06:17:18, )
>2012-07-21 16:00:11.497+0000: 6042: debug : virInitialize:409 : register drivers
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDriver:714 : driver=0x39ee4c2980 name=Test
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDriver:729 : registering Test as driver 0
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterNetworkDriver:546 : registering Test as network driver 0
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterInterfaceDriver:576 : registering Test as interface driver 0
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterStorageDriver:606 : registering Test as storage driver 0
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDeviceMonitor:636 : registering Test as device driver 0
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterSecretDriver:666 : registering Test as secret driver 0
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterNWFilterDriver:696 : registering Test as network filter driver 0
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDriver:714 : driver=0x39ee4c4500 name=OPENVZ
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDriver:729 : registering OPENVZ as driver 1
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDriver:714 : driver=0x39ee4c4a40 name=VMWARE
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDriver:729 : registering VMWARE as driver 2
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDriver:714 : driver=0x39ee4c3dc0 name=PHYP
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterDriver:729 : registering PHYP as driver 3
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterStorageDriver:606 : registering PHYP as storage driver 1
>2012-07-21 16:00:11.497+0000: 6042: debug : virRegisterInterfaceDriver:576 : registering PHYP as interface driver 1
>2012-07-21 16:00:11.498+0000: 6042: debug : vboxRegister:137 : VBoxCGlueInit failed, using dummy driver
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDriver:714 : driver=0x39ee4c4f80 name=VBOX
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDriver:729 : registering VBOX as driver 4
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterNetworkDriver:546 : registering VBOX as network driver 1
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterStorageDriver:606 : registering VBOX as storage driver 2
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDriver:714 : driver=0x39ee4c8040 name=ESX
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDriver:729 : registering ESX as driver 5
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterInterfaceDriver:576 : registering ESX as interface driver 2
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterNetworkDriver:546 : registering ESX as network driver 2
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterStorageDriver:606 : registering ESX as storage driver 3
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDeviceMonitor:636 : registering ESX as device driver 1
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterSecretDriver:666 : registering ESX as secret driver 1
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterNWFilterDriver:696 : registering ESX as network filter driver 1
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDriver:714 : driver=0x39ee4c8940 name=Hyper-V
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDriver:729 : registering Hyper-V as driver 6
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterInterfaceDriver:576 : registering Hyper-V as interface driver 3
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterNetworkDriver:546 : registering Hyper-V as network driver 3
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterStorageDriver:606 : registering Hyper-V as storage driver 4
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDeviceMonitor:636 : registering Hyper-V as device driver 2
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterSecretDriver:666 : registering Hyper-V as secret driver 2
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterNWFilterDriver:696 : registering Hyper-V as network filter driver 2
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDriver:714 : driver=0x39ee4c3280 name=remote
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDriver:729 : registering remote as driver 7
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterNetworkDriver:546 : registering remote as network driver 4
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterInterfaceDriver:576 : registering remote as interface driver 4
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterStorageDriver:606 : registering remote as storage driver 5
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterDeviceMonitor:636 : registering remote as device driver 3
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterSecretDriver:666 : registering remote as secret driver 3
>2012-07-21 16:00:11.498+0000: 6042: debug : virRegisterNWFilterDriver:696 : registering remote as network filter driver 3
>2012-07-21 16:00:11.498+0000: 6042: debug : virEventRegisterDefaultImpl:204 : registering default event implementation
>2012-07-21 16:00:11.498+0000: 6042: debug : virEventPollAddHandle:115 : Used 0 handle slots, adding at least 10 more
>2012-07-21 16:00:11.498+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 0
>2012-07-21 16:00:11.498+0000: 6042: debug : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=1 fd=4 events=1 cb=0x39ee056870 opaque=(nil) ff=(nil)
>2012-07-21 16:00:11.498+0000: 6042: debug : virEventRegisterImpl:177 : addHandle=0x39ee057380 updateHandle=0x39ee057270 removeHandle=0x39ee056c90 addTimeout=0x39ee056df0 updateTimeout=0x39ee056fc0 removeTimeout=0x39ee0570f0
>2012-07-21 16:00:11.498+0000: 6042: debug : virConnectOpenAuth:1385 : name=(null), auth=0x39ee4c2900, flags=0
>2012-07-21 16:00:11.498+0000: 6042: debug : virConnectGetConfigFile:938 : Loading config file '/etc/libvirt/libvirt.conf'
>2012-07-21 16:00:11.498+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.498+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.498+0000: 6042: debug : virFileClose:70 : Closed fd 6
>2012-07-21 16:00:11.498+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.498+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 1
>2012-07-21 16:00:11.498+0000: 6042: debug : do_open:1116 : no name, allowing driver auto-select
>2012-07-21 16:00:11.498+0000: 6042: debug : do_open:1156 : trying driver 0 (Test) ...
>2012-07-21 16:00:11.498+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.498+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.498+0000: 6042: debug : do_open:1162 : driver 0 Test returned DECLINED
>2012-07-21 16:00:11.498+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.498+0000: 6042: debug : do_open:1156 : trying driver 1 (OPENVZ) ...
>2012-07-21 16:00:11.498+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1162 : driver 1 OPENVZ returned DECLINED
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1156 : trying driver 2 (VMWARE) ...
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1162 : driver 2 VMWARE returned DECLINED
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1156 : trying driver 3 (PHYP) ...
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1162 : driver 3 PHYP returned DECLINED
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1156 : trying driver 4 (VBOX) ...
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1162 : driver 4 VBOX returned DECLINED
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1156 : trying driver 5 (ESX) ...
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1162 : driver 5 ESX returned DECLINED
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1156 : trying driver 6 (Hyper-V) ...
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1162 : driver 6 Hyper-V returned DECLINED
>2012-07-21 16:00:11.499+0000: 6042: debug : do_open:1156 : trying driver 7 (remote) ...
>2012-07-21 16:00:11.499+0000: 6042: debug : remoteOpen:865 : Auto-probe remote URI
>2012-07-21 16:00:11.499+0000: 6042: debug : doRemoteOpen:542 : proceeding with name = 
>2012-07-21 16:00:11.499+0000: 6042: debug : doRemoteOpen:552 : Connecting with transport 1
>2012-07-21 16:00:11.499+0000: 6042: debug : doRemoteOpen:599 : Proceeding with sockname /var/run/libvirt/libvirt-sock
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetSocketNew:119 : localAddr=0x7fffe0a4ef60 remoteAddr=0x7fffe0a4eff0 fd=6 errfd=-1 pid=0
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetSocketNew:179 : RPC_SOCKET_NEW: sock=0x8f4000 refs=1 fd=6 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetSocketRef:713 : RPC_SOCKET_REF: sock=0x8f4000 refs=2
>2012-07-21 16:00:11.499+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.499+0000: 6042: debug : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=2 fd=6 events=1 cb=0x39ee13db00 opaque=0x8f4000 ff=0x39ee13e150
>2012-07-21 16:00:11.499+0000: 6042: debug : virKeepAliveNew:206 : client=0x8f4300, interval=-1, count=0
>2012-07-21 16:00:11.499+0000: 6042: debug : virKeepAliveNew:230 : RPC_KEEPALIVE_NEW: ka=0x8f4280 client=0x8f4300 refs=1
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetClientNew:337 : RPC_CLIENT_NEW: client=0x8f4300 refs=3 sock=0x8f4000
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.499+0000: 6042: debug : doRemoteOpen:684 : Trying authentication
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetMessageNew:48 : msg=0x8f4410 tracked=0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetMessageEncodePayload:361 : Encode length as 28
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetClientSendInternal:1757 : RPC_CLIENT_MSG_TX_QUEUE: client=0x8f4300 len=28 prog=536903814 vers=1 proc=66 type=0 status=0 serial=0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetClientCallNew:1710 : New call 0x8f3950: msg=0x8f4410, expectReply=1, nonBlock=0
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetClientIO:1527 : Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0 length=28 dispatch=(nil)
>2012-07-21 16:00:11.499+0000: 6042: debug : virNetClientIO:1586 : We have the buck head=0x8f3950 call=0x8f3950
>2012-07-21 16:00:11.499+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=1 w=2, f=6 e=1 d=0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=2 timeout=-1
>2012-07-21 16:00:11.499+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 2
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.499+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetMessageDecodeLength:155 : Got length, now need 36 total (32 more)
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetClientCallDispatch:948 : RPC_CLIENT_MSG_RX: client=0x8f4300 len=36 prog=536903814 vers=1 proc=66 type=1 status=0 serial=0
>2012-07-21 16:00:11.500+0000: 6042: debug : virKeepAliveCheckMessage:402 : ka=0x8f4280, client=0x8f4300, msg=0x8f4358
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1242 : Giving up the buck 0x8f3950
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1256 : No thread to pass the buck to
>2012-07-21 16:00:11.500+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
>2012-07-21 16:00:11.500+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetClientIO:1616 : All done with our call head=(nil) call=0x8f3950 rv=0
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetMessageFree:76 : msg=0x8f4410 nfds=0 cb=(nil)
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetMessageNew:48 : msg=0x8f4410 tracked=0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetMessageEncodePayload:361 : Encode length as 32
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetClientSendInternal:1757 : RPC_CLIENT_MSG_TX_QUEUE: client=0x8f4300 len=32 prog=536903814 vers=1 proc=60 type=0 status=0 serial=1
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetClientCallNew:1710 : New call 0x8f3950: msg=0x8f4410, expectReply=1, nonBlock=0
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetClientIO:1527 : Outgoing message prog=536903814 version=1 serial=1 proc=60 type=0 length=32 dispatch=(nil)
>2012-07-21 16:00:11.500+0000: 6042: debug : virNetClientIO:1586 : We have the buck head=0x8f3950 call=0x8f3950
>2012-07-21 16:00:11.500+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.500+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -253008128
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.500+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetMessageDecodeLength:155 : Got length, now need 32 total (28 more)
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetClientCallDispatch:948 : RPC_CLIENT_MSG_RX: client=0x8f4300 len=32 prog=536903814 vers=1 proc=60 type=1 status=0 serial=1
>2012-07-21 16:00:11.501+0000: 6042: debug : virKeepAliveCheckMessage:402 : ka=0x8f4280, client=0x8f4300, msg=0x8f4358
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1242 : Giving up the buck 0x8f3950
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1256 : No thread to pass the buck to
>2012-07-21 16:00:11.501+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
>2012-07-21 16:00:11.501+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetClientIO:1616 : All done with our call head=(nil) call=0x8f3950 rv=0
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetMessageFree:76 : msg=0x8f4410 nfds=0 cb=(nil)
>2012-07-21 16:00:11.501+0000: 6042: debug : doRemoteOpen:710 : Trying to open URI 
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetMessageNew:48 : msg=0x8f3f20 tracked=0
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetMessageEncodePayload:361 : Encode length as 40
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetClientSendInternal:1757 : RPC_CLIENT_MSG_TX_QUEUE: client=0x8f4300 len=40 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetClientCallNew:1710 : New call 0x8f3dd0: msg=0x8f3f20, expectReply=1, nonBlock=0
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetClientIO:1527 : Outgoing message prog=536903814 version=1 serial=2 proc=1 type=0 length=40 dispatch=(nil)
>2012-07-21 16:00:11.501+0000: 6042: debug : virNetClientIO:1586 : We have the buck head=0x8f3dd0 call=0x8f3dd0
>2012-07-21 16:00:11.501+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.501+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -253008128
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.501+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-07-21 16:00:11.502+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.502+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.502+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetMessageDecodeLength:155 : Got length, now need 216 total (212 more)
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetClientCallDispatch:948 : RPC_CLIENT_MSG_RX: client=0x8f4300 len=216 prog=536903814 vers=1 proc=1 type=1 status=1 serial=2
>2012-07-21 16:00:11.502+0000: 6042: debug : virKeepAliveCheckMessage:402 : ka=0x8f4280, client=0x8f4300, msg=0x8f4358
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1242 : Giving up the buck 0x8f3dd0
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1256 : No thread to pass the buck to
>2012-07-21 16:00:11.502+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
>2012-07-21 16:00:11.502+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetClientIO:1616 : All done with our call head=(nil) call=0x8f3dd0 rv=0
>2012-07-21 16:00:11.502+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetMessageFree:76 : msg=0x8f3f20 nfds=0 cb=(nil)
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetClientClose:526 : client=0x8f4300
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1242 : Giving up the buck (nil)
>2012-07-21 16:00:11.502+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.502+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1256 : No thread to pass the buck to
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.503+0000: 6042: debug : virNetClientCloseLocked:494 : client=0x8f4300, sock=0x8f4000
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.503+0000: 6042: debug : virEventPollRemoveHandle:179 : EVENT_POLL_REMOVE_HANDLE: watch=2
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.503+0000: 6042: debug : virEventPollRemoveHandle:192 : mark delete 1 6
>2012-07-21 16:00:11.503+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -253008128
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.503+0000: 6042: debug : virNetSocketFree:726 : RPC_SOCKET_FREE: sock=0x8f4000 refs=2
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.503+0000: 6042: debug : virKeepAliveStop:338 : RPC_KEEPALIVE_STOP: ka=0x8f4280 client=0x8f4300
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCleanupHandles:566 : EVENT_POLL_PURGE_HANDLE: watch=2
>2012-07-21 16:00:11.503+0000: 6042: debug : virKeepAliveFree:257 : RPC_KEEPALIVE_FREE: ka=0x8f4280 client=0x8f4300 refs=1
>2012-07-21 16:00:11.503+0000: 6043: debug : virNetClientFree:459 : RPC_CLIENT_FREE: client=0x8f4300 refs=4
>2012-07-21 16:00:11.503+0000: 6043: debug : virNetSocketFree:726 : RPC_SOCKET_FREE: sock=0x8f4000 refs=1
>2012-07-21 16:00:11.503+0000: 6042: debug : virNetClientFree:459 : RPC_CLIENT_FREE: client=0x8f4300 refs=3
>2012-07-21 16:00:11.503+0000: 6043: debug : virNetSocketFree:734 : sock=0x8f4000 fd=6
>2012-07-21 16:00:11.503+0000: 6042: debug : virNetClientFree:459 : RPC_CLIENT_FREE: client=0x8f4300 refs=1
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollRemoveHandle:179 : EVENT_POLL_REMOVE_HANDLE: watch=2
>2012-07-21 16:00:11.503+0000: 6042: debug : virFileClose:70 : Closed fd 8
>2012-07-21 16:00:11.503+0000: 6042: debug : virFileClose:70 : Closed fd 7
>2012-07-21 16:00:11.503+0000: 6043: debug : virFileClose:70 : Closed fd 6
>2012-07-21 16:00:11.503+0000: 6042: debug : do_open:1162 : driver 7 remote returned ERROR
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.503+0000: 6042: debug : virUnrefConnect:145 : unref connection 0x8f3830 1
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.503+0000: 6042: debug : virReleaseConnect:94 : release connection 0x8f3830
>2012-07-21 16:00:11.503+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>error: Failed to reconnect to the hypervisor
>error: no valid connection
>error: no connection driver available for No connection for URI (null)
>2012-07-21 16:00:11.504+0000: 6042: debug : virConnectOpenAuth:1385 : name=(null), auth=0x39ee4c2900, flags=0
>2012-07-21 16:00:11.504+0000: 6042: debug : virConnectGetConfigFile:938 : Loading config file '/etc/libvirt/libvirt.conf'
>2012-07-21 16:00:11.504+0000: 6042: debug : virFileClose:70 : Closed fd 6
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1116 : no name, allowing driver auto-select
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1156 : trying driver 0 (Test) ...
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1162 : driver 0 Test returned DECLINED
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1156 : trying driver 1 (OPENVZ) ...
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1162 : driver 1 OPENVZ returned DECLINED
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1156 : trying driver 2 (VMWARE) ...
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1162 : driver 2 VMWARE returned DECLINED
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1156 : trying driver 3 (PHYP) ...
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1162 : driver 3 PHYP returned DECLINED
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1156 : trying driver 4 (VBOX) ...
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1162 : driver 4 VBOX returned DECLINED
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1156 : trying driver 5 (ESX) ...
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1162 : driver 5 ESX returned DECLINED
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1156 : trying driver 6 (Hyper-V) ...
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1162 : driver 6 Hyper-V returned DECLINED
>2012-07-21 16:00:11.504+0000: 6042: debug : do_open:1156 : trying driver 7 (remote) ...
>2012-07-21 16:00:11.504+0000: 6042: debug : remoteOpen:865 : Auto-probe remote URI
>2012-07-21 16:00:11.504+0000: 6042: debug : doRemoteOpen:542 : proceeding with name = 
>2012-07-21 16:00:11.504+0000: 6042: debug : doRemoteOpen:552 : Connecting with transport 1
>2012-07-21 16:00:11.504+0000: 6042: debug : doRemoteOpen:599 : Proceeding with sockname /var/run/libvirt/libvirt-sock
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetSocketNew:119 : localAddr=0x7fffe0a4ef60 remoteAddr=0x7fffe0a4eff0 fd=6 errfd=-1 pid=0
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetSocketNew:179 : RPC_SOCKET_NEW: sock=0x8f54d0 refs=1 fd=6 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetSocketRef:713 : RPC_SOCKET_REF: sock=0x8f54d0 refs=2
>2012-07-21 16:00:11.504+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.504+0000: 6042: debug : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=3 fd=6 events=1 cb=0x39ee13db00 opaque=0x8f54d0 ff=0x39ee13e150
>2012-07-21 16:00:11.504+0000: 6042: debug : virKeepAliveNew:206 : client=0x8f57d0, interval=-1, count=0
>2012-07-21 16:00:11.504+0000: 6042: debug : virKeepAliveNew:230 : RPC_KEEPALIVE_NEW: ka=0x8f5750 client=0x8f57d0 refs=1
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetClientNew:337 : RPC_CLIENT_NEW: client=0x8f57d0 refs=3 sock=0x8f54d0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.504+0000: 6042: debug : doRemoteOpen:684 : Trying authentication
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetMessageNew:48 : msg=0x8f58e0 tracked=0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetMessageEncodePayload:361 : Encode length as 28
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetClientSendInternal:1757 : RPC_CLIENT_MSG_TX_QUEUE: client=0x8f57d0 len=28 prog=536903814 vers=1 proc=66 type=0 status=0 serial=0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetClientCallNew:1710 : New call 0x8f2ea0: msg=0x8f58e0, expectReply=1, nonBlock=0
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetClientIO:1527 : Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0 length=28 dispatch=(nil)
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.504+0000: 6042: debug : virNetClientIO:1586 : We have the buck head=0x8f2ea0 call=0x8f2ea0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.504+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=3 events=0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.504+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -253008128
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=1 w=3, f=6 e=0 d=0
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.504+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetMessageDecodeLength:155 : Got length, now need 36 total (32 more)
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetClientCallDispatch:948 : RPC_CLIENT_MSG_RX: client=0x8f57d0 len=36 prog=536903814 vers=1 proc=66 type=1 status=0 serial=0
>2012-07-21 16:00:11.505+0000: 6042: debug : virKeepAliveCheckMessage:402 : ka=0x8f5750, client=0x8f57d0, msg=0x8f5828
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1242 : Giving up the buck 0x8f2ea0
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1256 : No thread to pass the buck to
>2012-07-21 16:00:11.505+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=3 events=1
>2012-07-21 16:00:11.505+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetClientIO:1616 : All done with our call head=(nil) call=0x8f2ea0 rv=0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetMessageFree:76 : msg=0x8f58e0 nfds=0 cb=(nil)
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetMessageNew:48 : msg=0x8f58e0 tracked=0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetMessageEncodePayload:361 : Encode length as 32
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetClientSendInternal:1757 : RPC_CLIENT_MSG_TX_QUEUE: client=0x8f57d0 len=32 prog=536903814 vers=1 proc=60 type=0 status=0 serial=1
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetClientCallNew:1710 : New call 0x8f50e0: msg=0x8f58e0, expectReply=1, nonBlock=0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetClientIO:1527 : Outgoing message prog=536903814 version=1 serial=1 proc=60 type=0 length=32 dispatch=(nil)
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.505+0000: 6042: debug : virNetClientIO:1586 : We have the buck head=0x8f50e0 call=0x8f50e0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.505+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=3 events=0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.505+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -253008128
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=1 w=3, f=6 e=0 d=0
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.505+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetMessageDecodeLength:155 : Got length, now need 32 total (28 more)
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetClientCallDispatch:948 : RPC_CLIENT_MSG_RX: client=0x8f57d0 len=32 prog=536903814 vers=1 proc=60 type=1 status=0 serial=1
>2012-07-21 16:00:11.506+0000: 6042: debug : virKeepAliveCheckMessage:402 : ka=0x8f5750, client=0x8f57d0, msg=0x8f5828
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1242 : Giving up the buck 0x8f50e0
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1256 : No thread to pass the buck to
>2012-07-21 16:00:11.506+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=3 events=1
>2012-07-21 16:00:11.506+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetClientIO:1616 : All done with our call head=(nil) call=0x8f50e0 rv=0
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetMessageFree:76 : msg=0x8f58e0 nfds=0 cb=(nil)
>2012-07-21 16:00:11.506+0000: 6042: debug : doRemoteOpen:710 : Trying to open URI 
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetMessageNew:48 : msg=0x8f53f0 tracked=0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetMessageEncodePayload:361 : Encode length as 40
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetClientSendInternal:1757 : RPC_CLIENT_MSG_TX_QUEUE: client=0x8f57d0 len=40 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetClientCallNew:1710 : New call 0x8f52a0: msg=0x8f53f0, expectReply=1, nonBlock=0
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetClientIO:1527 : Outgoing message prog=536903814 version=1 serial=2 proc=1 type=0 length=40 dispatch=(nil)
>2012-07-21 16:00:11.506+0000: 6042: debug : virNetClientIO:1586 : We have the buck head=0x8f52a0 call=0x8f52a0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.506+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=3 events=0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.506+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -253008128
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=1 w=3, f=6 e=0 d=0
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-21 16:00:11.506+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-07-21 16:00:11.507+0000: 6042: debug : virNetMessageDecodeLength:155 : Got length, now need 216 total (212 more)
>2012-07-21 16:00:11.507+0000: 6042: debug : virNetClientCallDispatch:948 : RPC_CLIENT_MSG_RX: client=0x8f57d0 len=216 prog=536903814 vers=1 proc=1 type=1 status=1 serial=2
>2012-07-21 16:00:11.507+0000: 6042: debug : virKeepAliveCheckMessage:402 : ka=0x8f5750, client=0x8f57d0, msg=0x8f5828
>2012-07-21 16:00:11.507+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1242 : Giving up the buck 0x8f52a0
>2012-07-21 16:00:11.507+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1256 : No thread to pass the buck to
>2012-07-21 16:00:11.507+0000: 6042: debug : virEventPollUpdateHandle:150 : EVENT_POLL_UPDATE_HANDLE: watch=3 events=1
>2012-07-21 16:00:11.507+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.507+0000: 6042: debug : virNetClientIO:1616 : All done with our call head=(nil) call=0x8f52a0 rv=0
>2012-07-21 16:00:11.507+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.507+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 0
>2012-07-21 16:00:11.507+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.508+0000: 6042: debug : virNetMessageFree:76 : msg=0x8f53f0 nfds=0 cb=(nil)
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.508+0000: 6042: debug : virNetClientClose:526 : client=0x8f57d0
>2012-07-21 16:00:11.508+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1242 : Giving up the buck (nil)
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.508+0000: 6042: debug : virNetClientIOEventLoopPassTheBuck:1256 : No thread to pass the buck to
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.508+0000: 6042: debug : virNetClientCloseLocked:494 : client=0x8f57d0, sock=0x8f54d0
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.508+0000: 6042: debug : virEventPollRemoveHandle:179 : EVENT_POLL_REMOVE_HANDLE: watch=3
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-21 16:00:11.508+0000: 6042: debug : virEventPollRemoveHandle:192 : mark delete 1 6
>2012-07-21 16:00:11.508+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -253008128
>2012-07-21 16:00:11.508+0000: 6042: debug : virNetSocketFree:726 : RPC_SOCKET_FREE: sock=0x8f54d0 refs=2
>2012-07-21 16:00:11.508+0000: 6042: debug : virKeepAliveStop:338 : RPC_KEEPALIVE_STOP: ka=0x8f5750 client=0x8f57d0
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-21 16:00:11.508+0000: 6042: debug : virKeepAliveFree:257 : RPC_KEEPALIVE_FREE: ka=0x8f5750 client=0x8f57d0 refs=1
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-21 16:00:11.508+0000: 6042: debug : virNetClientFree:459 : RPC_CLIENT_FREE: client=0x8f57d0 refs=4
>2012-07-21 16:00:11.508+0000: 6042: debug : virNetClientFree:459 : RPC_CLIENT_FREE: client=0x8f57d0 refs=2
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 2
>2012-07-21 16:00:11.508+0000: 6042: debug : do_open:1162 : driver 7 remote returned ERROR
>2012-07-21 16:00:11.508+0000: 6043: debug : virEventPollCleanupHandles:566 : EVENT_POLL_PURGE_HANDLE: watch=3
>2012-07-21 16:00:11.508+0000: 6042: debug : virUnrefConnect:145 : unref connection 0x8f2b40 1
>2012-07-21 16:00:11.508+0000: 6043: debug : virNetClientFree:459 : RPC_CLIENT_FREE: client=0x8f57d0 refs=1
>2012-07-21 16:00:11.508+0000: 6042: debug : virReleaseConnect:94 : release connection 0x8f2b40
>2012-07-21 16:00:11.508+0000: 6043: debug : virFileClose:70 : Closed fd 8
>2012-07-21 16:00:11.508+0000: 6043: debug : virFileClose:70 : Closed fd 7
>2012-07-21 16:00:11.552+0000: 6043: debug : virNetSocketFree:726 : RPC_SOCKET_FREE: sock=0x8f54d0 refs=1
>2012-07-21 16:00:11.552+0000: 6043: debug : virNetSocketFree:734 : sock=0x8f54d0 fd=6
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollRemoveHandle:179 : EVENT_POLL_REMOVE_HANDLE: watch=3
>2012-07-21 16:00:11.552+0000: 6043: debug : virFileClose:70 : Closed fd 6
>2012-07-21 16:00:11.552+0000: 6042: debug : virEventPollAddTimeout:224 : Used 0 timeout slots, adding at least 10 more
>2012-07-21 16:00:11.552+0000: 6042: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-21 16:00:11.552+0000: 6042: debug : virEventPollAddTimeout:247 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=0 cb=0x40bf20 opaque=(nil) ff=(nil)
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 1 timers
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollCalculateTimeout:330 : Got a timeout scheduled for 1342886411552
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollCalculateTimeout:350 : Timeout at 1342886411552 due in 0 ms
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=0
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollDispatchTimeouts:414 : Dispatch 1
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollDispatchTimeouts:437 : EVENT_POLL_DISPATCH_TIMEOUT: timer=1
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollCleanupTimeouts:505 : Cleanup 1
>2012-07-21 16:00:11.552+0000: 6043: debug : virEventPollCleanupHandles:553 : Cleanup 1
>2012-07-21 16:00:11.552+0000: 6042: debug : virEventPollRemoveTimeout:292 : EVENT_POLL_REMOVE_TIMEOUT: timer=1
>2012-07-21 16:00:11.552+0000: 6042: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -253008128
>

Actions: View

Attachments on bug 842068: 599536