Ooops, forgot to attach the logs
Hi there,
As the newer windows binaries kindly provided by teuf won't work
because of missing DLLs, I returned to the latest binaries provided by
spice-space.org.
remove-viewer.exe works fine, after I foud where to put TLS
certificates. Not that user-friendly though. :-)
virt-viewer and virsh won't connect, although they are using the same
certificates as a Linux client.
The short-term goal is getting virt-manager to work, butI think it'd
be easier to get virsh working first, but the solution would apply to
virt-manager as well.
Microsoft SystemInternals ProccessMonitor shows the certificates are
being found and read (that's how I found where to put then). I assume
that's ok. But after that nothing I can use for troubleshooting. Looks
like a bug on the windows port networking code.
But I finally found how to use libvirt own debugging features. So
here's attached a log for the windows machine, which can't connect,
and the linux machine, which connects fine to the same kvm host, using
the same certificates and the same URL (to the same CentOS 6.3 kvm
host). They are using different virsh and libvirt releases, so I added
to the logs the output of "virsh -V". Both machines are on the same
level-2 network, vlan and IP subnet.
I hope this helps someone find the bug and provide me with new
binaries to test. :-)
If someone helps me getting the missing DLLs for teuf newer binaries,
I can generate a log using them. It looks the missing DLLs is another
bug per se.
Of course, I hope someonte at Red Hat realizes a missing or broken
windows ports hurts KVM and RHEL and RHEV market share and put more
people on it. :-)
PS: Someone offered helping me compiling the windows port. I'll give
it a try, no promises, free time is very scarse. :-(
[]s, Fernando Lozano
c:> virsh.exe -V
Virsh command line tool of libvirt 0.10.2
See web site at http://libvirt.org/
Compiled with support for:
Hypervisors: PHYP ESX Test
Networking: Remote
Storage:
Miscellaneous: Debug
2013-09-13 14:12:35.762+0000: 7812: info : libvirt version: 0.10.2
2013-09-13 14:12:35.762+0000: 7812: warning : virLogParseFilters:1082 : Ignoring invalid log filter setting.
2013-09-13 14:12:35.762+0000: 7812: warning : virLogParseOutputs:1021 : Ignoring invalid log output setting.
2013-09-13 14:12:35.762+0000: 7812: debug : virInitialize:421 : register drivers
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDriver:729 : driver=000000006CD69160 name=Test
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDriver:744 : registering Test as driver 0
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterNetworkDriver:561 : registering Test as network driver 0
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterInterfaceDriver:591 : registering Test as interface driver 0
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterStorageDriver:621 : registering Test as storage driver 0
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDeviceMonitor:651 : registering Test as device driver 0
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterSecretDriver:681 : registering Test as secret driver 0
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterNWFilterDriver:711 : registering Test as network filter driver 0
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDriver:729 : driver=000000006CD6A4A0 name=PHYP
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDriver:744 : registering PHYP as driver 1
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterStorageDriver:621 : registering PHYP as storage driver 1
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterInterfaceDriver:591 : registering PHYP as interface driver 1
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDriver:729 : driver=000000006CD6AA40 name=ESX
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDriver:744 : registering ESX as driver 2
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterInterfaceDriver:591 : registering ESX as interface driver 2
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterNetworkDriver:561 : registering ESX as network driver 1
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterStorageDriver:621 : registering ESX as storage driver 2
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDeviceMonitor:651 : registering ESX as device driver 1
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterSecretDriver:681 : registering ESX as secret driver 1
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterNWFilterDriver:711 : registering ESX as network filter driver 1
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDriver:729 : driver=000000006CD69B00 name=remote
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDriver:744 : registering remote as driver 3
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterNetworkDriver:561 : registering remote as network driver 2
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterInterfaceDriver:591 : registering remote as interface driver 3
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterStorageDriver:621 : registering remote as storage driver 3
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterDeviceMonitor:651 : registering remote as device driver 2
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterSecretDriver:681 : registering remote as secret driver 2
2013-09-13 14:12:35.762+0000: 7812: debug : virRegisterNWFilterDriver:711 : registering remote as network filter driver 2
2013-09-13 14:12:35.777+0000: 7812: debug : virEventRegisterDefaultImpl:204 : registering default event implementation
2013-09-13 14:12:35.777+0000: 7812: debug : virEventPollAddHandle:111 : Used 0 handle slots, adding at least 10 more
2013-09-13 14:12:35.777+0000: 7812: debug : virEventPollInterruptLocked:697 : Skip interrupt, 0 0
2013-09-13 14:12:35.777+0000: 7812: debug : virEventPollAddHandle:136 : EVENT_POLL_ADD_HANDLE: watch=1 fd=3 events=1 cb=000000006CC08F80 opaque=0000000000000000 ff=0000000000000000
2013-09-13 14:12:35.777+0000: 7812: debug : virEventRegisterImpl:177 : addHandle=000000006CC09570 updateHandle=000000006CC09870 removeHandle=000000006CC08FC0 addTimeout=000000006CC09120 updateTimeout=000000006CC092C0 removeTimeout=000000006CC093F0
2013-09-13 14:12:35.777+0000: 7812: debug : virConnectOpenAuth:1405 : name=qemu://kvmhost/system, auth=000000006CD68C80, flags=0
2013-09-13 14:12:35.777+0000: 7812: debug : virObjectNew:110 : OBJECT_NEW: obj=00000000004D1770 classname=virConnect
2013-09-13 14:12:35.777+0000: 7712: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:12:35.777+0000: 7712: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
2013-09-13 14:12:35.777+0000: 7712: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
2013-09-13 14:12:35.777+0000: 7712: debug : virEventPollCleanupHandles:549 : Cleanup 1
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1127 : name "qemu://kvmhost/system" to URI components:
scheme qemu
server kvmhost
user (null)
port 0
path /system
2013-09-13 14:12:35.777+0000: 7712: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=3 e=1 d=0
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1174 : trying driver 0 (Test) ...
2013-09-13 14:12:35.777+0000: 7712: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1180 : driver 0 Test returned DECLINED
2013-09-13 14:12:35.777+0000: 7712: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1174 : trying driver 1 (PHYP) ...
2013-09-13 14:12:35.777+0000: 7712: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1180 : driver 1 PHYP returned DECLINED
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1174 : trying driver 2 (ESX) ...
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1180 : driver 2 ESX returned DECLINED
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1174 : trying driver 3 (remote) ...
2013-09-13 14:12:35.777+0000: 7812: debug : doRemoteOpen:576 : proceeding with name = qemu:///system
2013-09-13 14:12:35.777+0000: 7812: debug : doRemoteOpen:585 : Connecting with transport 0
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLocateCredentials:773 : pkipath=(NULL) isServer=0 tryUserPkiPath=0
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLocateCredentials:845 : Using default TLS CA certificate path
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLocateCredentials:851 : Using default TLS CA revocation list path
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLocateCredentials:857 : Using default TLS key/certificate path
2013-09-13 14:12:35.777+0000: 7812: debug : virObjectNew:110 : OBJECT_NEW: obj=0000000000309D40 classname=virNetTLSContext
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLoadCertFromFile:510 : isServer 0 isCA 0 certFile /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/libvirt/clientcert.pem
2013-09-13 14:12:35.777+0000: 7812: debug : virFileClose:72 : Closed fd 5
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLoadCertFromFile:510 : isServer 0 isCA 0 certFile /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/CA/cacert.pem
2013-09-13 14:12:35.777+0000: 7812: debug : virFileClose:72 : Closed fd 5
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextCheckCertBasicConstraints:181 : Cert /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/libvirt/clientcert.pem basic constraints 0
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextCheckCertKeyUsage:227 : Cert /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/libvirt/clientcert.pem key usage status 0 usage 224 critical 0
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextCheckCertKeyPurpose:299 : No key purpose data available at slot 0
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextCheckCertBasicConstraints:181 : Cert /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/CA/cacert.pem basic constraints 1
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextCheckCertKeyUsage:227 : Cert /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/CA/cacert.pem key usage status 0 usage 6 critical 0
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLoadCredentials:596 : loading CA cert from /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/CA/cacert.pem
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLoadCredentials:625 : Skipping non-existent CA CRL /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/CA/cacrl.pem
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextLoadCredentials:638 : loading cert and key from /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/libvirt/clientcert.pem and /usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/libvirt/private/clientkey.pem
2013-09-13 14:12:35.777+0000: 7812: debug : virNetTLSContextNew:743 : RPC_TLS_CONTEXT_NEW: ctxt=0000000000309D40 cacert=/usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/CA/cacert.pem cacrl=/usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/CA/cacrl.pem cert=/usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/libvirt/clientcert.pem key=/usr/x86_64-w64-mingw32/sys-root/mingw/etc/pki/libvirt/private/clientkey.pem sanityCheckCert=1 requireValidCert=1 isServer=0
2013-09-13 14:12:35.777+0000: 7812: debug : virNetSocketNew:146 : localAddr=000000000022F3F0 remoteAddr=000000000022F480 fd=5 errfd=-1 pid=0
2013-09-13 14:12:35.777+0000: 7812: debug : virFileClose:72 : Closed fd 5
2013-09-13 14:12:35.777+0000: 7812: debug : virNetClientCloseInternal:698 : client=0000000000000000 wantclose=0
2013-09-13 14:12:35.777+0000: 7812: debug : do_open:1180 : driver 3 remote returned ERROR
2013-09-13 14:12:35.777+0000: 7812: debug : virObjectUnref:135 : OBJECT_UNREF: obj=00000000004D1770
2013-09-13 14:12:35.777+0000: 7812: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=00000000004D1770
error: Unable to set close-on-exec flag: Success
error: failed to connect to the hypervisor
2013-09-13 14:12:35.777+0000: 7812: debug : virEventPollAddTimeout:220 : Used 0 timeout slots, adding at least 10 more
2013-09-13 14:12:35.777+0000: 7812: debug : virEventPollInterruptLocked:701 : Interrupting
2013-09-13 14:12:35.777+0000: 7812: debug : virEventPollAddTimeout:243 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=0 cb=0000000000401520 opaque=0000000000000000 ff=0000000000000000
2013-09-13 14:12:35.793+0000: 7712: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
2013-09-13 14:12:35.793+0000: 7712: debug : virEventPollDispatchTimeouts:410 : Dispatch 1
2013-09-13 14:12:35.793+0000: 7712: debug : virEventPollDispatchTimeouts:433 : EVENT_POLL_DISPATCH_TIMEOUT: timer=1
2013-09-13 14:12:35.793+0000: 7712: debug : virEventPollDispatchHandles:455 : Dispatch 1
2013-09-13 14:12:35.793+0000: 7712: debug : virEventPollDispatchHandles:469 : i=0 w=1
2013-09-13 14:12:35.793+0000: 7712: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:12:35.793+0000: 7712: debug : virEventPollCleanupTimeouts:501 : Cleanup 1
2013-09-13 14:12:35.793+0000: 7712: debug : virEventPollCleanupHandles:549 : Cleanup 1
2013-09-13 14:12:35.793+0000: 7812: debug : virEventPollRemoveTimeout:288 : EVENT_POLL_REMOVE_TIMEOUT: timer=1
2013-09-13 14:12:35.793+0000: 7812: debug : virEventPollInterruptLocked:697 : Skip interrupt, 0 232
$ virsh -V
Virsh command line tool of libvirt 0.9.10
See web site at http://libvirt.org/
Compiled with support for:
Hypervisors: QEmu/KVM LXC ESX Test
Networking: Remote Daemon Network Bridging Netcf Nwfilter VirtualPort
Storage: Dir Disk Filesystem SCSI Multipath iSCSI LVM
Miscellaneous: SELinux Secrets Debug DTrace Readline
2013-09-13 14:14:41.042+0000: 16962: info : libvirt version: 0.9.10, package: 21.el6 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2012-05-23-09:15:11, x86-003.build.bos.redhat.com)
2013-09-13 14:14:41.042+0000: 16962: debug : virInitialize:414 : register drivers
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDriver:775 : driver=0x373bbfe560 name=Test
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDriver:799 : registering Test as driver 0
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterNetworkDriver:592 : registering Test as network driver 0
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterInterfaceDriver:625 : registering Test as interface driver 0
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterStorageDriver:658 : registering Test as storage driver 0
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDeviceMonitor:691 : registering Test as device driver 0
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterSecretDriver:724 : registering Test as secret driver 0
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterNWFilterDriver:757 : registering Test as network filter driver 0
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDriver:775 : driver=0x373bbff920 name=ESX
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDriver:799 : registering ESX as driver 1
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterInterfaceDriver:625 : registering ESX as interface driver 1
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterNetworkDriver:592 : registering ESX as network driver 1
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterStorageDriver:658 : registering ESX as storage driver 1
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDeviceMonitor:691 : registering ESX as device driver 1
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterSecretDriver:724 : registering ESX as secret driver 1
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterNWFilterDriver:757 : registering ESX as network filter driver 1
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDriver:775 : driver=0x373bbfee40 name=remote
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDriver:799 : registering remote as driver 2
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterNetworkDriver:592 : registering remote as network driver 2
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterInterfaceDriver:625 : registering remote as interface driver 2
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterStorageDriver:658 : registering remote as storage driver 2
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterDeviceMonitor:691 : registering remote as device driver 2
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterSecretDriver:724 : registering remote as secret driver 2
2013-09-13 14:14:41.042+0000: 16962: debug : virRegisterNWFilterDriver:757 : registering remote as network filter driver 2
2013-09-13 14:14:41.042+0000: 16962: debug : virEventRegisterDefaultImpl:204 : registering default event implementation
2013-09-13 14:14:41.043+0000: 16962: debug : virEventPollAddHandle:116 : Used 0 handle slots, adding at least 10 more
2013-09-13 14:14:41.043+0000: 16962: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 0
2013-09-13 14:14:41.043+0000: 16962: debug : virEventPollAddHandle:141 : EVENT_POLL_ADD_HANDLE: watch=1 fd=4 events=1 cb=0x373b8475c0 opaque=(nil) ff=(nil)
2013-09-13 14:14:41.043+0000: 16962: debug : virEventRegisterImpl:177 : addHandle=0x373b848830 updateHandle=0x373b847860 removeHandle=0x373b847710 addTimeout=0x373b848660 updateTimeout=0x373b847980 removeTimeout=0x373b847600
2013-09-13 14:14:41.043+0000: 16962: debug : virConnectOpenAuth:1421 : name=qemu://kvmhost/system, auth=0x373bbfe4e0, flags=0
2013-09-13 14:14:41.043+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.043+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 0
2013-09-13 14:14:41.043+0000: 16963: debug : virEventPollCleanupTimeouts:542 : Found 0 out of 0 timeout slots used, releasing 0
2013-09-13 14:14:41.043+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 1
2013-09-13 14:14:41.043+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.043+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 0 timers
2013-09-13 14:14:41.043+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.043+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.046+0000: 16962: debug : do_open:1151 : name "qemu://kvmhost/system" to URI components:
scheme qemu
opaque (null)
authority (null)
server kvmhost
user (null)
port 0
path /system
2013-09-13 14:14:41.046+0000: 16962: debug : do_open:1195 : trying driver 0 (Test) ...
2013-09-13 14:14:41.046+0000: 16962: debug : do_open:1201 : driver 0 Test returned DECLINED
2013-09-13 14:14:41.047+0000: 16962: debug : do_open:1195 : trying driver 1 (ESX) ...
2013-09-13 14:14:41.047+0000: 16962: debug : do_open:1201 : driver 1 ESX returned DECLINED
2013-09-13 14:14:41.047+0000: 16962: debug : do_open:1195 : trying driver 2 (remote) ...
2013-09-13 14:14:41.047+0000: 16962: debug : doRemoteOpen:542 : proceeding with name = qemu:///system
2013-09-13 14:14:41.047+0000: 16962: debug : doRemoteOpen:552 : Connecting with transport 0
2013-09-13 14:14:41.047+0000: 16962: debug : virNetTLSContextLocateCredentials:753 : pkipath=(null) isServer=0 tryUserPkiPath=1
2013-09-13 14:14:41.049+0000: 16962: debug : virNetTLSContextLocateCredentials:785 : Trying to find TLS user credentials in /home/lozano/.pki/libvirt
2013-09-13 14:14:41.049+0000: 16962: debug : virNetTLSContextLocateCredentials:831 : Using default TLS CA revocation list path
2013-09-13 14:14:41.049+0000: 16962: debug : virNetTLSContextLoadCertFromFile:489 : isServer 0 isCA 0 certFile /home/lozano/.pki/libvirt/clientcert.pem
2013-09-13 14:14:41.049+0000: 16962: debug : virNetTLSContextLoadCertFromFile:489 : isServer 0 isCA 0 certFile /home/lozano/.pki/libvirt/cacert.pem
2013-09-13 14:14:41.050+0000: 16962: debug : virNetTLSContextCheckCertBasicConstraints:160 : Cert /home/lozano/.pki/libvirt/clientcert.pem basic constraints 0
2013-09-13 14:14:41.050+0000: 16962: debug : virNetTLSContextCheckCertKeyUsage:206 : Cert /home/lozano/.pki/libvirt/clientcert.pem key usage status 0 usage 224 critical 0
2013-09-13 14:14:41.050+0000: 16962: debug : virNetTLSContextCheckCertKeyPurpose:278 : No key purpose data available at slot 0
2013-09-13 14:14:41.050+0000: 16962: debug : virNetTLSContextCheckCertBasicConstraints:160 : Cert /home/lozano/.pki/libvirt/cacert.pem basic constraints 1
2013-09-13 14:14:41.050+0000: 16962: debug : virNetTLSContextCheckCertKeyUsage:206 : Cert /home/lozano/.pki/libvirt/cacert.pem key usage status 0 usage 6 critical 0
2013-09-13 14:14:41.054+0000: 16962: debug : virNetTLSContextLoadCredentials:575 : loading CA cert from /home/lozano/.pki/libvirt/cacert.pem
2013-09-13 14:14:41.056+0000: 16962: debug : virNetTLSContextLoadCredentials:604 : Skipping non-existent CA CRL /etc/pki/CA/cacrl.pem
2013-09-13 14:14:41.056+0000: 16962: debug : virNetTLSContextLoadCredentials:617 : loading cert and key from /home/lozano/.pki/libvirt/clientcert.pem and /home/lozano/.pki/libvirt/clientkey.pem
2013-09-13 14:14:41.057+0000: 16962: debug : virNetTLSContextNew:723 : RPC_TLS_CONTEXT_NEW: ctxt=0xb68090 refs=1 cacert=/home/lozano/.pki/libvirt/cacert.pem cacrl=/etc/pki/CA/cacrl.pem cert=/home/lozano/.pki/libvirt/clientcert.pem key=/home/lozano/.pki/libvirt/clientkey.pem sanityCheckCert=1 requireValidCert=1 isServer=0
2013-09-13 14:14:41.059+0000: 16962: debug : virNetSocketNew:119 : localAddr=0x7fff9d24e020 remoteAddr=0x7fff9d24df90 fd=7 errfd=-1 pid=0
2013-09-13 14:14:41.059+0000: 16962: debug : virNetSocketNew:179 : RPC_SOCKET_NEW: sock=0xb70fc0 refs=1 fd=7 errfd=-1 pid=0 localAddr=192.168.0.8;59508, remoteAddr=192.168.0.7;16514
2013-09-13 14:14:41.059+0000: 16962: debug : virNetSocketRef:709 : RPC_SOCKET_REF: sock=0xb70fc0 refs=2
2013-09-13 14:14:41.059+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.059+0000: 16962: debug : virEventPollAddHandle:141 : EVENT_POLL_ADD_HANDLE: watch=2 fd=7 events=1 cb=0x373b9200a0 opaque=0xb70fc0 ff=0x373b9213a0
2013-09-13 14:14:41.059+0000: 16962: debug : virKeepAliveNew:244 : client=0x7f72c1f3e010, interval=-1, count=0
2013-09-13 14:14:41.059+0000: 16962: debug : virEventPollAddTimeout:225 : Used 0 timeout slots, adding at least 10 more
2013-09-13 14:14:41.059+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.059+0000: 16962: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=-1 cb=0x373b91f690 opaque=0xb6d320 ff=0x373b91fa60
2013-09-13 14:14:41.059+0000: 16962: debug : virKeepAliveNew:277 : RPC_KEEPALIVE_NEW: ka=0xb6d320 client=0x7f72c1f3e010 refs=2
2013-09-13 14:14:41.059+0000: 16962: debug : virNetClientNew:324 : RPC_CLIENT_NEW: client=0x7f72c1f3e010 refs=3 sock=0xb70fc0
2013-09-13 14:14:41.059+0000: 16962: debug : doRemoteOpen:570 : Starting TLS session
2013-09-13 14:14:41.059+0000: 16962: debug : virNetTLSSessionNew:1171 : ctxt=0xb68090 hostname=kvmhost isServer=0
2013-09-13 14:14:41.059+0000: 16962: debug : virNetTLSSessionNew:1237 : RPC_TLS_SESSION_NEW: sess=0xb712d0 refs=1 ctxt=0xb68090 hostname=kvmhost isServer=0
2013-09-13 14:14:41.059+0000: 16962: debug : virNetTLSSessionRef:1253 : RPC_TLS_SESSION_REF: sess=0xb712d0 refs=2
2013-09-13 14:14:41.059+0000: 16962: debug : virNetTLSSessionHandshake:1336 : sess=0xb712d0
2013-09-13 14:14:41.060+0000: 16962: debug : virNetTLSSessionHandshake:1339 : Ret=-28
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.060+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 2 event(s)
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchHandles:474 : i=1 w=2
2013-09-13 14:14:41.060+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=2 events=1
2013-09-13 14:14:41.060+0000: 16962: debug : virNetTLSSessionHandshake:1336 : sess=0xb712d0
2013-09-13 14:14:41.061+0000: 16962: debug : virNetTLSSessionHandshake:1339 : Ret=-28
2013-09-13 14:14:41.064+0000: 16962: debug : virNetTLSSessionHandshake:1336 : sess=0xb712d0
2013-09-13 14:14:41.083+0000: 16962: debug : virNetTLSSessionHandshake:1339 : Ret=-28
2013-09-13 14:14:41.085+0000: 16962: debug : virNetTLSSessionHandshake:1336 : sess=0xb712d0
2013-09-13 14:14:41.085+0000: 16962: debug : virNetTLSSessionHandshake:1339 : Ret=0
2013-09-13 14:14:41.085+0000: 16962: debug : virNetTLSSessionHandshake:1342 : Handshake is complete
2013-09-13 14:14:41.089+0000: 16962: debug : virNetTLSContextValidCertificate:1028 : Peer DN is C=BR,ST=RJ,L=Rio de Janeiro,O=IBP,OU=Suporte TI,CN=kvmhost,EMAIL=ti@xxxxxxxxxx
2013-09-13 14:14:41.089+0000: 16962: debug : virNetTLSContextCheckCertBasicConstraints:160 : Cert [session] basic constraints 0
2013-09-13 14:14:41.089+0000: 16962: debug : virNetTLSContextCheckCertKeyUsage:206 : Cert [session] key usage status 0 usage 224 critical 0
2013-09-13 14:14:41.089+0000: 16962: debug : virNetTLSContextCheckCertKeyPurpose:278 : No key purpose data available at slot 0
2013-09-13 14:14:41.089+0000: 16962: debug : virNetTLSContextValidCertificate:1065 : RPC_TLS_CONTEXT_SESSION_ALLOW: ctxt=0xb68090 sess=0xb712d0 dname=C=BR,ST=RJ,L=Rio de Janeiro,O=IBP,OU=Suporte TI,CN=kvmhost,EMAIL=ti@xxxxxxxxxx
2013-09-13 14:14:41.089+0000: 16963: debug : virNetClientIncomingEvent:1640 : Event fired 0xb70fc0 1
2013-09-13 14:14:41.089+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.089+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.089+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.090+0000: 16962: debug : doRemoteOpen:684 : Trying authentication
2013-09-13 14:14:41.090+0000: 16962: debug : virNetMessageNew:48 : msg=0x7f72c1efd010 tracked=0
2013-09-13 14:14:41.090+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 28
2013-09-13 14:14:41.090+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=28 prog=536903814 vers=1 proc=66 type=0 status=0 serial=0
2013-09-13 14:14:41.090+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0 length=28 dispatch=(nil)
2013-09-13 14:14:41.090+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb6ba30 0xb6ba30
2013-09-13 14:14:41.090+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.090+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.090+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.090+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.091+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 36 total (32 more)
2013-09-13 14:14:41.091+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=36 prog=536903814 vers=1 proc=66 type=1 status=0 serial=0
2013-09-13 14:14:41.091+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.091+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb6ba30
2013-09-13 14:14:41.091+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.091+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.091+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.091+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.091+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb6ba30 2
2013-09-13 14:14:41.091+0000: 16962: debug : virNetMessageFree:75 : msg=0x7f72c1efd010 nfds=0 cb=(nil)
2013-09-13 14:14:41.091+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.091+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 32
2013-09-13 14:14:41.091+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=32 prog=536903814 vers=1 proc=60 type=0 status=0 serial=1
2013-09-13 14:14:41.091+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=1 proc=60 type=0 length=32 dispatch=(nil)
2013-09-13 14:14:41.091+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb6ba30 0xb6ba30
2013-09-13 14:14:41.091+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.091+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.091+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.092+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.092+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.092+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 32 total (28 more)
2013-09-13 14:14:41.092+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=32 prog=536903814 vers=1 proc=60 type=1 status=0 serial=1
2013-09-13 14:14:41.092+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.093+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb6ba30
2013-09-13 14:14:41.093+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.093+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.093+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.093+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.093+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb6ba30 2
2013-09-13 14:14:41.093+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.093+0000: 16962: debug : doRemoteOpen:710 : Trying to open URI qemu:///system
2013-09-13 14:14:41.093+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.093+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 56
2013-09-13 14:14:41.093+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=56 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2
2013-09-13 14:14:41.093+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=2 proc=1 type=0 length=56 dispatch=(nil)
2013-09-13 14:14:41.093+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb6ba30 0xb6ba30
2013-09-13 14:14:41.093+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.093+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.093+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.093+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.099+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
2013-09-13 14:14:41.099+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=28 prog=536903814 vers=1 proc=1 type=1 status=0 serial=2
2013-09-13 14:14:41.099+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.099+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb6ba30
2013-09-13 14:14:41.099+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.099+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.099+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.099+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.099+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.099+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb6ba30 2
2013-09-13 14:14:41.099+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1201 : driver 2 remote returned SUCCESS
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1223 : network driver 0 Test returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1223 : network driver 1 ESX returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1223 : network driver 2 remote returned SUCCESS
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1238 : interface driver 0 Test returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1238 : interface driver 1 ESX returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1238 : interface driver 2 remote returned SUCCESS
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1254 : storage driver 0 Test returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1254 : storage driver 1 ESX returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1254 : storage driver 2 remote returned SUCCESS
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1270 : node driver 0 Test returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1270 : node driver 1 ESX returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1270 : node driver 2 remote returned SUCCESS
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1286 : secret driver 0 Test returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1286 : secret driver 1 ESX returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1286 : secret driver 2 remote returned SUCCESS
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1302 : nwfilter driver 0 Test returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1302 : nwfilter driver 1 ESX returned DECLINED
2013-09-13 14:14:41.099+0000: 16962: debug : do_open:1302 : nwfilter driver 2 remote returned SUCCESS
2013-09-13 14:14:41.099+0000: 16962: debug : virConnectNumOfDomains:1874 : conn=0xb67770
2013-09-13 14:14:41.099+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.099+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 28
2013-09-13 14:14:41.099+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=28 prog=536903814 vers=1 proc=51 type=0 status=0 serial=3
2013-09-13 14:14:41.099+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=3 proc=51 type=0 length=28 dispatch=(nil)
2013-09-13 14:14:41.100+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb681d0 0xb681d0
2013-09-13 14:14:41.100+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.100+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.100+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.100+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.101+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 32 total (28 more)
2013-09-13 14:14:41.101+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=32 prog=536903814 vers=1 proc=51 type=1 status=0 serial=3
2013-09-13 14:14:41.101+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.101+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb681d0
2013-09-13 14:14:41.101+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.101+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.101+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.101+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.101+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb681d0 2
2013-09-13 14:14:41.101+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.101+0000: 16962: debug : virConnectListDomains:1835 : conn=0xb67770, ids=0xb58040, maxids=2
2013-09-13 14:14:41.101+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.101+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 32
2013-09-13 14:14:41.101+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=32 prog=536903814 vers=1 proc=37 type=0 status=0 serial=4
2013-09-13 14:14:41.101+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=4 proc=37 type=0 length=32 dispatch=(nil)
2013-09-13 14:14:41.101+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb681d0 0xb681d0
2013-09-13 14:14:41.101+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.101+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.101+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.101+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.102+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.102+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.102+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.102+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 40 total (36 more)
2013-09-13 14:14:41.102+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=40 prog=536903814 vers=1 proc=37 type=1 status=0 serial=4
2013-09-13 14:14:41.102+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.102+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb681d0
2013-09-13 14:14:41.102+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.102+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.102+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.102+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.102+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.103+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.103+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb681d0 2
2013-09-13 14:14:41.103+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.103+0000: 16962: debug : virDomainLookupByID:2022 : conn=0xb67770, id=14
2013-09-13 14:14:41.103+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.103+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 32
2013-09-13 14:14:41.103+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=32 prog=536903814 vers=1 proc=22 type=0 status=0 serial=5
2013-09-13 14:14:41.103+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=5 proc=22 type=0 length=32 dispatch=(nil)
2013-09-13 14:14:41.103+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb6b4b0 0xb6b4b0
2013-09-13 14:14:41.103+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.103+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.103+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.103+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.104+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.104+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.117+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 68 total (64 more)
2013-09-13 14:14:41.117+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=68 prog=536903814 vers=1 proc=22 type=1 status=0 serial=5
2013-09-13 14:14:41.117+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.117+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb6b4b0
2013-09-13 14:14:41.117+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.117+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.117+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.117+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.117+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.117+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb6b4b0 2
2013-09-13 14:14:41.117+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.117+0000: 16962: debug : virDomainGetState:4275 : dom=0xb6ba30, (VM: name=lnxServArqCnt, uuid=d57aeb63-5fc9-3bb7-54c7-ba3c4767aa07), state=0x7fff9d24e3ac, reason=(nil), flags=0
2013-09-13 14:14:41.117+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.117+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 72
2013-09-13 14:14:41.117+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=72 prog=536903814 vers=1 proc=212 type=0 status=0 serial=6
2013-09-13 14:14:41.117+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=6 proc=212 type=0 length=72 dispatch=(nil)
2013-09-13 14:14:41.117+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb6b4b0 0xb6b4b0
2013-09-13 14:14:41.118+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.118+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.118+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.118+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.119+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 36 total (32 more)
2013-09-13 14:14:41.119+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=36 prog=536903814 vers=1 proc=212 type=1 status=0 serial=6
2013-09-13 14:14:41.119+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.119+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb6b4b0
2013-09-13 14:14:41.119+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.119+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.119+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.119+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.119+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.119+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb6b4b0 2
2013-09-13 14:14:41.119+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.119+0000: 16962: debug : virDomainGetName:3383 : domain=0xb6ba30
2013-09-13 14:14:41.119+0000: 16962: debug : virDomainGetID:3478 : dom=0xb6ba30, (VM: name=lnxServArqCnt, uuid=d57aeb63-5fc9-3bb7-54c7-ba3c4767aa07)
2013-09-13 14:14:41.119+0000: 16962: debug : virDomainFree:2313 : dom=0xb6ba30, (VM: name=lnxServArqCnt, uuid=d57aeb63-5fc9-3bb7-54c7-ba3c4767aa07)
2013-09-13 14:14:41.119+0000: 16962: debug : virUnrefDomain:276 : unref domain 0xb6ba30 lnxServArqCnt 1
2013-09-13 14:14:41.119+0000: 16962: debug : virReleaseDomain:238 : release domain 0xb6ba30 lnxServArqCnt d57aeb63-5fc9-3bb7-54c7-ba3c4767aa07
2013-09-13 14:14:41.119+0000: 16962: debug : virReleaseDomain:246 : unref connection 0xb67770 2
2013-09-13 14:14:41.119+0000: 16962: debug : virDomainLookupByID:2022 : conn=0xb67770, id=17
2013-09-13 14:14:41.119+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.119+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 32
2013-09-13 14:14:41.119+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=32 prog=536903814 vers=1 proc=22 type=0 status=0 serial=7
2013-09-13 14:14:41.119+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=7 proc=22 type=0 length=32 dispatch=(nil)
2013-09-13 14:14:41.119+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb6b680 0xb6b680
2013-09-13 14:14:41.119+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.119+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.120+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.120+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.121+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 64 total (60 more)
2013-09-13 14:14:41.121+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=64 prog=536903814 vers=1 proc=22 type=1 status=0 serial=7
2013-09-13 14:14:41.121+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.121+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb6b680
2013-09-13 14:14:41.121+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.121+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.121+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.121+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.121+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb6b680 2
2013-09-13 14:14:41.121+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.121+0000: 16962: debug : virDomainGetState:4275 : dom=0xb6bcc0, (VM: name=lnxservti, uuid=9e98d16d-c304-d58d-2210-481d779cc04b), state=0x7fff9d24e3ac, reason=(nil), flags=0
2013-09-13 14:14:41.121+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.121+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 68
2013-09-13 14:14:41.121+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=68 prog=536903814 vers=1 proc=212 type=0 status=0 serial=8
2013-09-13 14:14:41.121+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=8 proc=212 type=0 length=68 dispatch=(nil)
2013-09-13 14:14:41.121+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb6b680 0xb6b680
2013-09-13 14:14:41.121+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.121+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.121+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.122+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.122+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.122+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.122+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.122+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.122+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.122+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.122+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.122+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 36 total (32 more)
2013-09-13 14:14:41.122+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=36 prog=536903814 vers=1 proc=212 type=1 status=0 serial=8
2013-09-13 14:14:41.122+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.122+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb6b680
2013-09-13 14:14:41.122+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.122+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.123+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.123+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.123+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb6b680 2
2013-09-13 14:14:41.123+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.123+0000: 16962: debug : virDomainGetName:3383 : domain=0xb6bcc0
2013-09-13 14:14:41.123+0000: 16962: debug : virDomainGetID:3478 : dom=0xb6bcc0, (VM: name=lnxservti, uuid=9e98d16d-c304-d58d-2210-481d779cc04b)
2013-09-13 14:14:41.123+0000: 16962: debug : virDomainFree:2313 : dom=0xb6bcc0, (VM: name=lnxservti, uuid=9e98d16d-c304-d58d-2210-481d779cc04b)
2013-09-13 14:14:41.123+0000: 16962: debug : virUnrefDomain:276 : unref domain 0xb6bcc0 lnxservti 1
2013-09-13 14:14:41.123+0000: 16962: debug : virReleaseDomain:238 : release domain 0xb6bcc0 lnxservti 9e98d16d-c304-d58d-2210-481d779cc04b
2013-09-13 14:14:41.123+0000: 16962: debug : virReleaseDomain:246 : unref connection 0xb67770 2
2013-09-13 14:14:41.123+0000: 16962: debug : virConnectClose:1462 : conn=0xb67770
2013-09-13 14:14:41.123+0000: 16962: debug : virUnrefConnect:145 : unref connection 0xb67770 1
2013-09-13 14:14:41.123+0000: 16962: debug : virReleaseConnect:94 : release connection 0xb67770
2013-09-13 14:14:41.123+0000: 16962: debug : virNetMessageNew:48 : msg=0xb7b750 tracked=0
2013-09-13 14:14:41.123+0000: 16962: debug : virNetMessageEncodePayload:351 : Encode length as 28
2013-09-13 14:14:41.123+0000: 16962: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f72c1f3e010 len=28 prog=536903814 vers=1 proc=2 type=0 status=0 serial=9
2013-09-13 14:14:41.123+0000: 16962: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=9 proc=2 type=0 length=28 dispatch=(nil)
2013-09-13 14:14:41.123+0000: 16962: debug : virNetClientIO:1591 : We have the buck 0xb6b680 0xb6b680
2013-09-13 14:14:41.123+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2013-09-13 14:14:41.123+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.123+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=0 d=0
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.123+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.124+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.124+0000: 16962: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
2013-09-13 14:14:41.124+0000: 16962: debug : virNetClientCallDispatch:926 : RPC_CLIENT_MSG_RX: client=0x7f72c1f3e010 len=28 prog=536903814 vers=1 proc=2 type=1 status=0 serial=9
2013-09-13 14:14:41.124+0000: 16962: debug : virKeepAliveCheckMessage:408 : ka=0xb6d320, client=0x7f72c1f3e010, msg=0x7f72c1f3e068
2013-09-13 14:14:41.124+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1246 : Giving up the buck 0xb6b680
2013-09-13 14:14:41.124+0000: 16962: debug : virNetClientIOEventLoopPassTheBuck:1260 : No thread to pass the buck to
2013-09-13 14:14:41.124+0000: 16962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2013-09-13 14:14:41.124+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.124+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.124+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.124+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.124+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.125+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=7 e=1 d=0
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2013-09-13 14:14:41.125+0000: 16962: debug : virNetClientIO:1620 : All done with our call (nil) 0xb6b680 2
2013-09-13 14:14:41.125+0000: 16962: debug : virNetMessageFree:75 : msg=0xb7b750 nfds=0 cb=(nil)
2013-09-13 14:14:41.125+0000: 16962: debug : virNetTLSContextFree:1120 : RPC_TLS_CONTEXT_FREE: ctxt=0xb68090 refs=1
2013-09-13 14:14:41.125+0000: 16962: debug : virNetClientClose:513 : client=0x7f72c1f3e010
2013-09-13 14:14:41.125+0000: 16962: debug : virNetClientCloseLocked:481 : client=0x7f72c1f3e010, sock=0xb70fc0
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 2
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollDispatchHandles:474 : i=1 w=2
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=2 events=1
2013-09-13 14:14:41.125+0000: 16962: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=2
2013-09-13 14:14:41.125+0000: 16962: debug : virEventPollRemoveHandle:193 : mark delete 1 7
2013-09-13 14:14:41.125+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.125+0000: 16962: debug : virNetSocketFree:722 : RPC_SOCKET_FREE: sock=0xb70fc0 refs=2
2013-09-13 14:14:41.125+0000: 16962: debug : virNetTLSSessionFree:1407 : RPC_TLS_SESSION_FREE: sess=0xb712d0 refs=2
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 2
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupHandles:567 : EVENT_POLL_PURGE_HANDLE: watch=2
2013-09-13 14:14:41.125+0000: 16963: debug : virNetClientFree:446 : RPC_CLIENT_FREE: client=0x7f72c1f3e010 refs=4
2013-09-13 14:14:41.125+0000: 16963: debug : virNetSocketFree:722 : RPC_SOCKET_FREE: sock=0xb70fc0 refs=1
2013-09-13 14:14:41.125+0000: 16963: debug : virNetSocketFree:730 : sock=0xb70fc0 fd=7
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=2
2013-09-13 14:14:41.125+0000: 16963: debug : virNetTLSSessionFree:1407 : RPC_TLS_SESSION_FREE: sess=0xb712d0 refs=1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 1
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.125+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.126+0000: 16962: debug : virKeepAliveStop:382 : RPC_KEEPALIVE_STOP: ka=0xb6d320 client=0x7f72c1f3e010
2013-09-13 14:14:41.126+0000: 16962: debug : virEventPollRemoveTimeout:293 : EVENT_POLL_REMOVE_TIMEOUT: timer=1
2013-09-13 14:14:41.126+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupTimeouts:519 : EVENT_POLL_PURGE_TIMEOUT: timer=1
2013-09-13 14:14:41.126+0000: 16963: debug : virKeepAliveFree:304 : RPC_KEEPALIVE_FREE: ka=0xb6d320 client=0x7f72c1f3e010 refs=2
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupTimeouts:542 : Found 0 out of 10 timeout slots used, releasing 10
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventRunDefaultImpl:244 : running default event implementation
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 0
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupTimeouts:542 : Found 0 out of 0 timeout slots used, releasing 0
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 0 timers
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2013-09-13 14:14:41.126+0000: 16962: debug : virKeepAliveFree:304 : RPC_KEEPALIVE_FREE: ka=0xb6d320 client=0x7f72c1f3e010 refs=1
2013-09-13 14:14:41.126+0000: 16962: debug : virNetClientFree:446 : RPC_CLIENT_FREE: client=0x7f72c1f3e010 refs=3
2013-09-13 14:14:41.126+0000: 16962: debug : virNetClientFree:446 : RPC_CLIENT_FREE: client=0x7f72c1f3e010 refs=1
2013-09-13 14:14:41.126+0000: 16962: debug : virEventPollAddTimeout:225 : Used 0 timeout slots, adding at least 10 more
2013-09-13 14:14:41.126+0000: 16962: debug : virEventPollInterruptLocked:706 : Interrupting
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2013-09-13 14:14:41.126+0000: 16962: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=2 frequency=0 cb=0x40af40 opaque=(nil) ff=(nil)
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchTimeouts:438 : EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:460 : Dispatch 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:474 : i=0 w=1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2013-09-13 14:14:41.126+0000: 16963: debug : virEventPollCleanupHandles:554 : Cleanup 1
2013-09-13 14:14:41.127+0000: 16962: debug : virEventPollRemoveTimeout:293 : EVENT_POLL_REMOVE_TIMEOUT: timer=2
2013-09-13 14:14:41.127+0000: 16962: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 -1021630720
commands: "list"
Id Nome Estado
----------------------------------------------------
[ommited not to reveal customer information]
_______________________________________________
virt-tools-list mailing list
virt-tools-list@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/virt-tools-list
