[virt-tools-list] More on virt-viewer for windows

Fri Sep 13 16:43:20 UTC 2013

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
>

-------------- next part --------------
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
-------------- next part --------------
$ 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 at ibp.org.br
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 at ibp.org.br
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]