Hi,
I have attached the log of both virsh -c ssh://root@192.168.1.40 & virsh -c xen+ssh://root@192.168.1.40
Hope this helps to debug. not for me,
On 11.08.16 18:09, Anantha Raghava wrote: please try to send the log and a small explanation that you try to connect via virsh to libvirt users mailing list at: libvirt-users@redhat.com.
--
Thanks & Regards,
Anantha Raghava
Do not print this e-mail unless required. Save Paper & trees.
On Thursday 11 August 2016 04:01 PM, Shahar Havivi wrote:
Hi,
Tested this with different combinations:
a. from VDSM host, both "ssh root@192.168.1.40" and "sudo -u vdsm ssh root@192.168.1.40" commands are logging in without asking for password and I can run all xe commands without any glitch without modifications to default xen server firewall or SELinux rules.
b. With firewall enabled and SELinux set to enforcing or permissive or disabled, I run "virsh -c ssh://root@192.168.1.40". And the command is resulting in two errors:
error: filed to connect to the hypervisor error: unable to connect to the server at '192.168.1.40:16514' : No route to the host.
c. With firewall disabled and SELinux set to Enforcing or permissive or disabled, I run "virsh -c ssh://192.168.1.40". And the command is resulting in two errors
error: filed to connect to the hypervisor error: unable to connect to the server at '192.168.1.40:16514' : Connection refused Good tests, We need to figure out why libvirt refuse the connection,
On 11.08.16 14:14, Anantha Raghava wrote: try to debug virsh by running:
$ export LIBVIRT_LOG_OUTPUTS="1:file:/tmp/libvirt_client.log" $ export LIBVIRT_DEBUG=1 $ virsh -c virsh -c ssh://192.168.1.40
and examing /tmp/libvirt_client.log file
--
Thanks & Regards,
Anantha Raghava
eXza Technology Consulting & Services
Ph: +91-9538849179, E-mail: raghav@exzatechconsulting.com <mailto:raghav@exzatechconsulting.com>
URL: http://www.exzatechconsulting.com <http://www.exzatechconsulting.com/>
/*Support No.: +91-7829774584 */
DISCLAIMER: This e-mail communication and any attachments may be privileged and confidential to eXza Technology Consulting & Services, and are intended only for the use of the recipients named above If you are not the addressee you may not copy, forward, disclose or use any part of it. If you have received this message in error, please delete it and all copies from your system and notify the sender immediately by return e-mail. Internet communications cannot be guaranteed to be timely, secure, error or virus-free. The sender does not accept liability for any errors or omissions.
Do not print this e-mail unless required. Save Paper & trees.
On Thursday 11 August 2016 12:20 PM, Shahar Havivi wrote:
On 10.08.16 19:40, Anantha Raghava wrote:
Hello Richard / Shahar,
I installed and enabled nc on Xen Server host. Now the " ...... sh: nc: command not found: Input/output error" is gone. Communication is established. However I am still getting two specific errors:
VDSM ovirt_engine command failed: End of file while reading data: : Input/Output error
&
Failed to retrieve VMs Information from the external server xen+ssh://root@192.168.1.40
I am receiving the same error when I run virsh -c xen+ssh://root@192.168.1.40
Screen shot is attached for quick reference.
Is it something to do with firewall / ip tables on xen server or libvirtd host? Hi, You don't need to try it on oVirt when 'virsh -c' doesn't work since oVirt try to connect via libvirt libraries (same as virsh) before it called virt-v2v.
Did you follow all the steps in the wiki? Are you able to ssh to the Xen server from the vdsm machine that you try to run virsh without password? (ssh root@192.168.1.40)
--
Thanks & Regards,
Anantha Raghava
Do not print this e-mail unless required. Save Paper & trees.
On Wednesday 10 August 2016 06:04 PM, Anantha Raghava wrote:
Hi,
Let me try this and post the results here.
Regards, Ananth
On 10 Aug 2016 15:28, "Richard W.M. Jones" <rjones@redhat.com <mailto:rjones@redhat.com>> wrote:
On Wed, Aug 10, 2016 at 09:45:52AM +0300, Shahar Havivi wrote: > On 10.08.16 06:45, Anantha Raghava wrote: > > Hi, > > > > I even attempted to run command virsh -c xen+ssh://root@xenhost and I get > > error "/*error: End of file reading data: sh: nc: command not found: > > Input/output error"*/ > First you need to be able to login via virsh (before trying to import via > oVirt). > > I never encounter this error before, > I guess that nc is netcat..., > try to install nmap-ncat: > $ dnf info nmap-ncat > > Adding Richard which may have more input.
Yes, you need to install 'nc' on the *target* (Xen) machine.
This is because libvirt's ssh transport uses nc: https://libvirt.org/guide/html/Application_Development_Guide-Architecture-Tr... <https://libvirt.org/guide/html/Application_Development_Guide-Architecture-Transports.html>
Rich.
-- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones <http://people.redhat.com/%7Erjones> Read my programming and virtualization blog: http://rwmj.wordpress.com virt-builder quickly builds VMs from scratch http://libguestfs.org/virt-builder.1.html <http://libguestfs.org/virt-builder.1.html>
------ from here you can see the debug log of command virsh -c ssh://root@192.168.1.40 ---------
2016-08-11 12:15:24.011+0000: 43283: info : libvirt version: 1.2.17, package: 13.el7_2.5 (CentOS BuildSystem <http://bugs.centos.org>, 2016-06-23-14:23:27, worker1.bsys.centos.org) 2016-08-11 12:15:24.011+0000: 43283: debug : virGlobalInit:389 : register drivers 2016-08-11 12:15:24.011+0000: 43283: debug : virRegisterConnectDriver:691 : driver=0x7f975826a640 name=Test 2016-08-11 12:15:24.011+0000: 43283: debug : virRegisterConnectDriver:702 : registering Test as driver 0 2016-08-11 12:15:24.011+0000: 43283: debug : virRegisterConnectDriver:691 : driver=0x7f975826c260 name=ESX 2016-08-11 12:15:24.011+0000: 43283: debug : virRegisterConnectDriver:702 : registering ESX as driver 1 2016-08-11 12:15:24.011+0000: 43283: debug : virRegisterConnectDriver:691 : driver=0x7f975826b0c0 name=remote 2016-08-11 12:15:24.011+0000: 43283: debug : virRegisterConnectDriver:702 : registering remote as driver 2 2016-08-11 12:15:24.011+0000: 43283: debug : virEventRegisterDefaultImpl:261 : registering default event implementation 2016-08-11 12:15:24.011+0000: 43283: debug : virEventPollAddHandle:115 : Used 0 handle slots, adding at least 10 more 2016-08-11 12:15:24.011+0000: 43283: debug : virEventPollInterruptLocked:723 : Skip interrupt, 0 0 2016-08-11 12:15:24.011+0000: 43283: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=1 fd=5 events=1 cb=0x7f9757da9920 opaque=(nil) ff=(nil) 2016-08-11 12:15:24.011+0000: 43283: debug : virEventRegisterImpl:231 : addHandle=0x7f9757daa080 updateHandle=0x7f9757daa3e0 removeHandle=0x7f9757da9980 addTimeout=0x7f9757da9b00 updateTimeout=0x7f9757da9d20 removeTimeout=0x7f9757da9ef0 2016-08-11 12:15:24.011+0000: 43283: debug : virEventPollAddTimeout:230 : Used 0 timeout slots, adding at least 10 more 2016-08-11 12:15:24.011+0000: 43283: debug : virEventPollInterruptLocked:723 : Skip interrupt, 0 0 2016-08-11 12:15:24.011+0000: 43283: info : virEventPollAddTimeout:253 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=-1 cb=0x7f97584b7c10 opaque=0x7ffe0aa3bc30 ff=(nil) 2016-08-11 12:15:24.011+0000: 43283: debug : virConnectOpenAuth:1339 : name=ssh://root@192.168.1.40, auth=0x7f975826a400, flags=0 2016-08-11 12:15:24.011+0000: 43283: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f97587985e0 classname=virConnect 2016-08-11 12:15:24.011+0000: 43283: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f9758797f20 classname=virConnectCloseCallbackData 2016-08-11 12:15:24.011+0000: 43283: debug : virConnectGetConfigFile:953 : Loading config file '/etc/libvirt/libvirt.conf' 2016-08-11 12:15:24.011+0000: 43283: debug : virConfReadFile:769 : filename=/etc/libvirt/libvirt.conf 2016-08-11 12:15:24.011+0000: 43284: debug : virThreadJobSet:99 : Thread 43284 is now running job vshEventLoop 2016-08-11 12:15:24.011+0000: 43283: debug : virFileClose:102 : Closed fd 7 2016-08-11 12:15:24.011+0000: 43284: debug : virEventRunDefaultImpl:305 : running default event implementation 2016-08-11 12:15:24.011+0000: 43284: debug : virEventPollCleanupTimeouts:526 : Cleanup 1 2016-08-11 12:15:24.011+0000: 43284: debug : virEventPollCleanupHandles:575 : Cleanup 1 2016-08-11 12:15:24.011+0000: 43284: debug : virEventPollMakePollFDs:401 : Prepare n=0 w=1, f=5 e=1 d=0 2016-08-11 12:15:24.011+0000: 43284: debug : virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers 2016-08-11 12:15:24.011+0000: 43284: debug : virEventPollCalculateTimeout:371 : No timeout is pending 2016-08-11 12:15:24.011+0000: 43284: info : virEventPollRunOnce:641 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2016-08-11 12:15:24.011+0000: 43283: debug : do_open:1132 : name "ssh://root@192.168.1.40" to URI components: scheme ssh server 192.168.1.40 user root port 0 path <null>
2016-08-11 12:15:24.011+0000: 43283: debug : do_open:1179 : trying driver 0 (Test) ... 2016-08-11 12:15:24.011+0000: 43283: debug : do_open:1194 : driver 0 Test returned DECLINED 2016-08-11 12:15:24.011+0000: 43283: debug : do_open:1179 : trying driver 1 (ESX) ... 2016-08-11 12:15:24.011+0000: 43283: debug : do_open:1194 : driver 1 ESX returned DECLINED 2016-08-11 12:15:24.011+0000: 43283: debug : do_open:1179 : trying driver 2 (remote) ... 2016-08-11 12:15:24.011+0000: 43283: debug : doRemoteOpen:792 : proceeding with name = ssh:// 2016-08-11 12:15:24.011+0000: 43283: debug : doRemoteOpen:801 : Connecting with transport 0 2016-08-11 12:15:24.011+0000: 43283: debug : virNetTLSContextLocateCredentials:813 : pkipath=(null) isServer=0 tryUserPkiPath=0 2016-08-11 12:15:24.011+0000: 43283: debug : virNetTLSContextLocateCredentials:885 : Using default TLS CA certificate path 2016-08-11 12:15:24.011+0000: 43283: debug : virNetTLSContextLocateCredentials:891 : Using default TLS CA revocation list path 2016-08-11 12:15:24.011+0000: 43283: debug : virNetTLSContextLocateCredentials:897 : Using default TLS key/certificate path 2016-08-11 12:15:24.011+0000: 43283: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f975879a9c0 classname=virNetTLSContext 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextLoadCertFromFile:516 : isServer 0 certFile /etc/pki/libvirt/clientcert.pem 2016-08-11 12:15:24.012+0000: 43283: debug : virFileClose:102 : Closed fd 7 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextLoadCACertListFromFile:560 : certFile /etc/pki/CA/cacert.pem 2016-08-11 12:15:24.012+0000: 43283: debug : virFileClose:102 : Closed fd 7 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextCheckCertBasicConstraints:189 : Cert /etc/pki/libvirt/clientcert.pem basic constraints 0 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextCheckCertKeyUsage:235 : Cert /etc/pki/libvirt/clientcert.pem key usage status 0 usage 160 critical 1 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextCheckCertKeyPurpose:335 : Key purpose 0 1.3.6.1.5.5.7.3.1 critical 1 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextCheckCertKeyPurpose:335 : Key purpose 0 1.3.6.1.5.5.7.3.2 critical 1 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextCheckCertKeyPurpose:307 : No key purpose data available at slot 2 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextCheckCertBasicConstraints:189 : Cert /etc/pki/CA/cacert.pem basic constraints 1 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextCheckCertKeyUsage:235 : Cert /etc/pki/CA/cacert.pem key usage status 0 usage 6 critical 1 2016-08-11 12:15:24.012+0000: 43283: debug : virNetTLSContextLoadCredentials:642 : loading CA cert from /etc/pki/CA/cacert.pem 2016-08-11 12:15:24.013+0000: 43283: debug : virNetTLSContextLoadCredentials:671 : Skipping non-existent CA CRL /etc/pki/CA/cacrl.pem 2016-08-11 12:15:24.013+0000: 43283: debug : virNetTLSContextLoadCredentials:684 : loading cert and key from /etc/pki/libvirt/clientcert.pem and /etc/pki/libvirt/private/clientkey.pem 2016-08-11 12:15:24.014+0000: 43283: info : virNetTLSContextNew:783 : RPC_TLS_CONTEXT_NEW: ctxt=0x7f975879a9c0 cacert=/etc/pki/CA/cacert.pem cacrl=/etc/pki/CA/cacrl.pem cert=/etc/pki/libvirt/clientcert.pem key=/etc/pki/libvirt/private/clientkey.pem sanityCheckCert=1 requireValidCert=1 isServer=0 2016-08-11 12:15:24.016+0000: 43283: debug : virFileClose:102 : Closed fd 7 2016-08-11 12:15:24.016+0000: 43283: error : virNetSocketNewConnectTCP:577 : unable to connect to server at '192.168.1.40:16514': Connection refused 2016-08-11 12:15:24.016+0000: 43283: debug : virNetClientCloseInternal:695 : client=(nil) wantclose=0 2016-08-11 12:15:24.016+0000: 43283: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f975879a9c0 2016-08-11 12:15:24.016+0000: 43283: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f975879a9c0 2016-08-11 12:15:24.016+0000: 43283: info : virNetTLSContextDispose:1169 : RPC_TLS_CONTEXT_DISPOSE: ctxt=0x7f975879a9c0 2016-08-11 12:15:24.016+0000: 43283: debug : do_open:1194 : driver 2 remote returned ERROR 2016-08-11 12:15:24.016+0000: 43283: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f97587985e0 2016-08-11 12:15:24.016+0000: 43283: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f97587985e0 2016-08-11 12:15:24.016+0000: 43283: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9758797f20 2016-08-11 12:15:24.016+0000: 43283: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f9758797f20 2016-08-11 12:15:24.016+0000: 43283: debug : virEventPollInterruptLocked:727 : Interrupting 2016-08-11 12:15:24.016+0000: 43283: info : virEventPollAddTimeout:253 : EVENT_POLL_ADD_TIMEOUT: timer=2 frequency=0 cb=0x7f97584b7ae0 opaque=(nil) ff=(nil) 2016-08-11 12:15:24.016+0000: 43284: debug : virEventPollRunOnce:651 : Poll got 1 event(s) 2016-08-11 12:15:24.016+0000: 43284: debug : virEventPollDispatchTimeouts:433 : Dispatch 2 2016-08-11 12:15:24.016+0000: 43284: info : virEventPollDispatchTimeouts:456 : EVENT_POLL_DISPATCH_TIMEOUT: timer=2 2016-08-11 12:15:24.016+0000: 43284: debug : virEventPollDispatchHandles:479 : Dispatch 1 2016-08-11 12:15:24.016+0000: 43284: debug : virEventPollDispatchHandles:493 : i=0 w=1 2016-08-11 12:15:24.016+0000: 43284: info : virEventPollDispatchHandles:507 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2016-08-11 12:15:24.016+0000: 43284: debug : virEventPollCleanupTimeouts:526 : Cleanup 2 2016-08-11 12:15:24.016+0000: 43284: debug : virEventPollCleanupHandles:575 : Cleanup 1 2016-08-11 12:15:24.016+0000: 43284: debug : virThreadJobClear:124 : Thread 43284 finished job vshEventLoop with ret=0 2016-08-11 12:15:24.016+0000: 43283: info : virEventPollRemoveTimeout:305 : EVENT_POLL_REMOVE_TIMEOUT: timer=2 2016-08-11 12:15:24.016+0000: 43283: debug : virEventPollInterruptLocked:723 : Skip interrupt, 0 140287726221056 2016-08-11 12:15:24.016+0000: 43283: info : virEventPollRemoveTimeout:305 : EVENT_POLL_REMOVE_TIMEOUT: timer=1 2016-08-11 12:15:24.016+0000: 43283: debug : virEventPollInterruptLocked:723 : Skip interrupt, 0 140287726221056
-------- from here you can see debug log of command virsh -c xen+ssh://root@192.168.1.40 -----------
2016-08-11 12:17:34.366+0000: 43669: info : libvirt version: 1.2.17, package: 13.el7_2.5 (CentOS BuildSystem <http://bugs.centos.org>, 2016-06-23-14:23:27, worker1.bsys.centos.org) 2016-08-11 12:17:34.366+0000: 43669: debug : virGlobalInit:389 : register drivers 2016-08-11 12:17:34.367+0000: 43669: debug : virRegisterConnectDriver:691 : driver=0x7f9661e6a640 name=Test 2016-08-11 12:17:34.367+0000: 43669: debug : virRegisterConnectDriver:702 : registering Test as driver 0 2016-08-11 12:17:34.367+0000: 43669: debug : virRegisterConnectDriver:691 : driver=0x7f9661e6c260 name=ESX 2016-08-11 12:17:34.367+0000: 43669: debug : virRegisterConnectDriver:702 : registering ESX as driver 1 2016-08-11 12:17:34.367+0000: 43669: debug : virRegisterConnectDriver:691 : driver=0x7f9661e6b0c0 name=remote 2016-08-11 12:17:34.367+0000: 43669: debug : virRegisterConnectDriver:702 : registering remote as driver 2 2016-08-11 12:17:34.367+0000: 43669: debug : virEventRegisterDefaultImpl:261 : registering default event implementation 2016-08-11 12:17:34.367+0000: 43669: debug : virEventPollAddHandle:115 : Used 0 handle slots, adding at least 10 more 2016-08-11 12:17:34.367+0000: 43669: debug : virEventPollInterruptLocked:723 : Skip interrupt, 0 0 2016-08-11 12:17:34.367+0000: 43669: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=1 fd=5 events=1 cb=0x7f96619a9920 opaque=(nil) ff=(nil) 2016-08-11 12:17:34.367+0000: 43669: debug : virEventRegisterImpl:231 : addHandle=0x7f96619aa080 updateHandle=0x7f96619aa3e0 removeHandle=0x7f96619a9980 addTimeout=0x7f96619a9b00 updateTimeout=0x7f96619a9d20 removeTimeout=0x7f96619a9ef0 2016-08-11 12:17:34.367+0000: 43669: debug : virEventPollAddTimeout:230 : Used 0 timeout slots, adding at least 10 more 2016-08-11 12:17:34.367+0000: 43669: debug : virEventPollInterruptLocked:723 : Skip interrupt, 0 0 2016-08-11 12:17:34.367+0000: 43669: info : virEventPollAddTimeout:253 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=-1 cb=0x7f96620b7c10 opaque=0x7ffef5e35180 ff=(nil) 2016-08-11 12:17:34.367+0000: 43669: debug : virConnectOpenAuth:1339 : name=xen+ssh://root@192.168.1.40, auth=0x7f9661e6a400, flags=0 2016-08-11 12:17:34.367+0000: 43669: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f9663423ec0 classname=virConnect 2016-08-11 12:17:34.367+0000: 43669: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f9663421f20 classname=virConnectCloseCallbackData 2016-08-11 12:17:34.367+0000: 43670: debug : virThreadJobSet:99 : Thread 43670 is now running job vshEventLoop 2016-08-11 12:17:34.367+0000: 43670: debug : virEventRunDefaultImpl:305 : running default event implementation 2016-08-11 12:17:34.367+0000: 43670: debug : virEventPollCleanupTimeouts:526 : Cleanup 1 2016-08-11 12:17:34.367+0000: 43670: debug : virEventPollCleanupHandles:575 : Cleanup 1 2016-08-11 12:17:34.367+0000: 43670: debug : virEventPollMakePollFDs:401 : Prepare n=0 w=1, f=5 e=1 d=0 2016-08-11 12:17:34.367+0000: 43669: debug : virConnectGetConfigFile:953 : Loading config file '/etc/libvirt/libvirt.conf' 2016-08-11 12:17:34.367+0000: 43670: debug : virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers 2016-08-11 12:17:34.367+0000: 43670: debug : virEventPollCalculateTimeout:371 : No timeout is pending 2016-08-11 12:17:34.367+0000: 43669: debug : virConfReadFile:769 : filename=/etc/libvirt/libvirt.conf 2016-08-11 12:17:34.367+0000: 43670: info : virEventPollRunOnce:641 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2016-08-11 12:17:34.367+0000: 43669: debug : virFileClose:102 : Closed fd 7 2016-08-11 12:17:34.367+0000: 43669: debug : do_open:1132 : name "xen+ssh://root@192.168.1.40" to URI components: scheme xen+ssh server 192.168.1.40 user root port 0 path <null>
2016-08-11 12:17:34.367+0000: 43669: debug : do_open:1179 : trying driver 0 (Test) ... 2016-08-11 12:17:34.367+0000: 43669: debug : do_open:1194 : driver 0 Test returned DECLINED 2016-08-11 12:17:34.367+0000: 43669: debug : do_open:1179 : trying driver 1 (ESX) ... 2016-08-11 12:17:34.367+0000: 43669: debug : do_open:1194 : driver 1 ESX returned DECLINED 2016-08-11 12:17:34.367+0000: 43669: debug : do_open:1179 : trying driver 2 (remote) ... 2016-08-11 12:17:34.367+0000: 43669: debug : doRemoteOpen:792 : proceeding with name = xen:// 2016-08-11 12:17:34.367+0000: 43669: debug : doRemoteOpen:801 : Connecting with transport 2 2016-08-11 12:17:34.368+0000: 43669: debug : virCommandRunAsync:2428 : About to run LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/root/bin HOME=/root USER=root LOGNAME=root ssh -l root 192.168.1.40 sh -c ''\''if '\''nc'\'' -q 2>&1 | grep "requires an argument" >/dev/null 2>&1; then ARG=-q0;else ARG=;fi;'\''nc'\'' $ARG -U /var/run/libvirt/libvirt-sock'\''' 2016-08-11 12:17:34.368+0000: 43669: debug : virCommandRunAsync:2431 : Command result 0, with PID 43671 2016-08-11 12:17:34.368+0000: 43669: debug : virFileClose:102 : Closed fd 8 2016-08-11 12:17:34.368+0000: 43669: debug : virFileClose:102 : Closed fd 10 2016-08-11 12:17:34.368+0000: 43669: debug : virNetSocketNew:225 : localAddr=(nil) remoteAddr=(nil) fd=7 errfd=9 pid=43671 2016-08-11 12:17:34.368+0000: 43669: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f9663424d90 classname=virNetSocket 2016-08-11 12:17:34.368+0000: 43669: info : virNetSocketNew:276 : RPC_SOCKET_NEW: sock=0x7f9663424d90 fd=7 errfd=9 pid=43671 localAddr=<null>, remoteAddr=<null> 2016-08-11 12:17:34.368+0000: 43669: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f9663424fd0 classname=virNetClient 2016-08-11 12:17:34.368+0000: 43669: info : virNetClientNew:327 : RPC_CLIENT_NEW: client=0x7f9663424fd0 sock=0x7f9663424d90 2016-08-11 12:17:34.368+0000: 43669: info : virObjectRef:296 : OBJECT_REF: obj=0x7f9663424fd0 2016-08-11 12:17:34.368+0000: 43669: info : virObjectRef:296 : OBJECT_REF: obj=0x7f9663424d90 2016-08-11 12:17:34.368+0000: 43669: debug : virEventPollInterruptLocked:727 : Interrupting 2016-08-11 12:17:34.368+0000: 43669: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=2 fd=7 events=1 cb=0x7f9661afbfb0 opaque=0x7f9663424d90 ff=0x7f9661afbf60 2016-08-11 12:17:34.368+0000: 43669: debug : virKeepAliveNew:199 : client=0x7f9663424fd0, interval=-1, count=0 2016-08-11 12:17:34.368+0000: 43669: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f9663424c10 classname=virKeepAlive 2016-08-11 12:17:34.368+0000: 43669: info : virKeepAliveNew:218 : RPC_KEEPALIVE_NEW: ka=0x7f9663424c10 client=0x7f9663424fd0 2016-08-11 12:17:34.368+0000: 43669: info : virObjectRef:296 : OBJECT_REF: obj=0x7f9663424fd0 2016-08-11 12:17:34.368+0000: 43669: info : virObjectRef:296 : OBJECT_REF: obj=0x7f9663421f20 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollRunOnce:651 : Poll got 1 event(s) 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollDispatchTimeouts:433 : Dispatch 1 2016-08-11 12:17:34.368+0000: 43669: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f96634249f0 classname=virNetClientProgram 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollDispatchHandles:479 : Dispatch 1 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollDispatchHandles:493 : i=0 w=1 2016-08-11 12:17:34.368+0000: 43669: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f9663424ba0 classname=virNetClientProgram 2016-08-11 12:17:34.368+0000: 43669: info : virObjectNew:202 : OBJECT_NEW: obj=0x7f9663424950 classname=virNetClientProgram 2016-08-11 12:17:34.368+0000: 43670: info : virEventPollDispatchHandles:507 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2016-08-11 12:17:34.368+0000: 43669: info : virObjectRef:296 : OBJECT_REF: obj=0x7f96634249f0 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCleanupTimeouts:526 : Cleanup 1 2016-08-11 12:17:34.368+0000: 43669: info : virObjectRef:296 : OBJECT_REF: obj=0x7f9663424ba0 2016-08-11 12:17:34.368+0000: 43669: info : virObjectRef:296 : OBJECT_REF: obj=0x7f9663424950 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCleanupHandles:575 : Cleanup 2 2016-08-11 12:17:34.368+0000: 43669: debug : doRemoteOpen:1010 : Trying authentication 2016-08-11 12:17:34.368+0000: 43670: debug : virEventRunDefaultImpl:305 : running default event implementation 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCleanupTimeouts:526 : Cleanup 1 2016-08-11 12:17:34.368+0000: 43669: debug : virNetMessageNew:46 : msg=0x7f96634251e0 tracked=0 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCleanupHandles:575 : Cleanup 2 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollMakePollFDs:401 : Prepare n=0 w=1, f=5 e=1 d=0 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollMakePollFDs:401 : Prepare n=1 w=2, f=7 e=1 d=0 2016-08-11 12:17:34.368+0000: 43669: debug : virNetMessageEncodePayload:376 : Encode length as 28 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers 2016-08-11 12:17:34.368+0000: 43669: info : virNetClientSendInternal:1950 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f9663424fd0 len=28 prog=536903814 vers=1 proc=66 type=0 status=0 serial=0 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCalculateTimeout:371 : No timeout is pending 2016-08-11 12:17:34.368+0000: 43669: debug : virNetClientCallNew:1903 : New call 0x7f9663425100: msg=0x7f96634251e0, expectReply=1, nonBlock=0 2016-08-11 12:17:34.368+0000: 43670: info : virEventPollRunOnce:641 : EVENT_POLL_RUN: nhandles=2 timeout=-1 2016-08-11 12:17:34.368+0000: 43669: debug : virNetClientIO:1712 : Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0 length=28 dispatch=(nil) 2016-08-11 12:17:34.368+0000: 43669: debug : virNetClientIO:1771 : We have the buck head=0x7f9663425100 call=0x7f9663425100 2016-08-11 12:17:34.368+0000: 43669: info : virEventPollUpdateHandle:152 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0 2016-08-11 12:17:34.368+0000: 43669: debug : virEventPollInterruptLocked:727 : Interrupting 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollRunOnce:651 : Poll got 1 event(s) 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollDispatchTimeouts:433 : Dispatch 1 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollDispatchHandles:479 : Dispatch 2 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollDispatchHandles:493 : i=0 w=1 2016-08-11 12:17:34.368+0000: 43670: info : virEventPollDispatchHandles:507 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCleanupTimeouts:526 : Cleanup 1 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCleanupHandles:575 : Cleanup 2 2016-08-11 12:17:34.368+0000: 43670: debug : virEventRunDefaultImpl:305 : running default event implementation 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCleanupTimeouts:526 : Cleanup 1 2016-08-11 12:17:34.368+0000: 43671: info : libvirt version: 1.2.17, package: 13.el7_2.5 (CentOS BuildSystem <http://bugs.centos.org>, 2016-06-23-14:23:27, worker1.bsys.centos.org) 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCleanupHandles:575 : Cleanup 2 2016-08-11 12:17:34.368+0000: 43671: debug : virExec:730 : Setting child uid:gid to -1:-1 with caps 0 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollMakePollFDs:401 : Prepare n=0 w=1, f=5 e=1 d=0 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollMakePollFDs:401 : Prepare n=1 w=2, f=7 e=0 d=0 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers 2016-08-11 12:17:34.368+0000: 43670: debug : virEventPollCalculateTimeout:371 : No timeout is pending 2016-08-11 12:17:34.368+0000: 43670: info : virEventPollRunOnce:641 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2016-08-11 12:17:34.632+0000: 43669: error : virNetSocketReadWire:1590 : End of file while reading data: 2016-08-11 12:17:34.368+0000: 43671: debug : virFileClose:102 : Closed fd 8 2016-08-11 12:17:34.368+0000: 43671: debug : virFileClose:102 : Closed fd 10 2016-08-11 12:17:34.368+0000: 43671: debug : virLogParseOutputs:1091 : outputs=1:file:/tmp/libvirt_client.log: Input/output error 2016-08-11 12:17:34.632+0000: 43669: debug : virNetClientMarkClose:638 : client=0x7f9663424fd0, reason=0 2016-08-11 12:17:34.632+0000: 43669: info : virEventPollRemoveHandle:186 : EVENT_POLL_REMOVE_HANDLE: watch=2 2016-08-11 12:17:34.632+0000: 43669: debug : virEventPollRemoveHandle:199 : mark delete 1 7 2016-08-11 12:17:34.632+0000: 43669: debug : virEventPollInterruptLocked:727 : Interrupting 2016-08-11 12:17:34.632+0000: 43669: debug : virNetClientIOEventLoopPassTheBuck:1419 : Giving up the buck 0x7f9663425100 2016-08-11 12:17:34.632+0000: 43669: debug : virNetClientIOEventLoopPassTheBuck:1433 : No thread to pass the buck to 2016-08-11 12:17:34.632+0000: 43669: debug : virNetClientCloseLocked:654 : client=0x7f9663424fd0, sock=0x7f9663424d90, reason=0 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424d90 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollRunOnce:651 : Poll got 1 event(s) 2016-08-11 12:17:34.632+0000: 43669: info : virObjectRef:296 : OBJECT_REF: obj=0x7f9663424fd0 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollDispatchTimeouts:433 : Dispatch 1 2016-08-11 12:17:34.632+0000: 43669: info : virKeepAliveStop:310 : RPC_KEEPALIVE_STOP: ka=0x7f9663424c10 client=0x7f9663424fd0 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424c10 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollDispatchHandles:479 : Dispatch 1 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f9663424c10 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollDispatchHandles:493 : i=0 w=1 2016-08-11 12:17:34.632+0000: 43669: info : virKeepAliveDispose:230 : RPC_KEEPALIVE_DISPOSE: ka=0x7f9663424c10 2016-08-11 12:17:34.632+0000: 43670: info : virEventPollDispatchHandles:507 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424fd0 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollCleanupTimeouts:526 : Cleanup 1 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424fd0 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollCleanupHandles:575 : Cleanup 2 2016-08-11 12:17:34.632+0000: 43669: debug : virNetClientIO:1801 : All done with our call head=(nil) call=0x7f9663425100 rv=-1 2016-08-11 12:17:34.632+0000: 43670: info : virEventPollCleanupHandles:588 : EVENT_POLL_PURGE_HANDLE: watch=2 2016-08-11 12:17:34.632+0000: 43669: debug : virNetMessageFree:74 : msg=0x7f96634251e0 nfds=0 cb=(nil) 2016-08-11 12:17:34.632+0000: 43670: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424fd0 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f96634249f0 2016-08-11 12:17:34.632+0000: 43670: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424d90 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424ba0 2016-08-11 12:17:34.632+0000: 43670: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f9663424d90 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424950 2016-08-11 12:17:34.632+0000: 43670: info : virNetSocketDispose:1155 : RPC_SOCKET_DISPOSE: sock=0x7f9663424d90 2016-08-11 12:17:34.632+0000: 43669: debug : virNetClientCloseInternal:695 : client=0x7f9663424fd0 wantclose=0 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424fd0 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f9663424fd0 2016-08-11 12:17:34.632+0000: 43669: info : virNetClientDispose:606 : RPC_CLIENT_DISPOSE: client=0x7f9663424fd0 2016-08-11 12:17:34.632+0000: 43670: debug : virFileClose:102 : Closed fd 7 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663421f20 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f96634249f0 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f96634249f0 2016-08-11 12:17:34.632+0000: 43670: debug : virFileClose:102 : Closed fd 9 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424ba0 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f9663424ba0 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663424950 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f9663424950 2016-08-11 12:17:34.632+0000: 43670: debug : virProcessAbort:167 : aborting child process 43671 2016-08-11 12:17:34.632+0000: 43669: debug : virFileClose:102 : Closed fd 10 2016-08-11 12:17:34.632+0000: 43669: debug : virFileClose:102 : Closed fd 8 2016-08-11 12:17:34.632+0000: 43669: debug : virNetMessageClear:57 : msg=0x7f9663425038 nfds=0 2016-08-11 12:17:34.632+0000: 43669: debug : do_open:1194 : driver 2 remote returned ERROR 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663423ec0 2016-08-11 12:17:34.632+0000: 43670: debug : virProcessAbort:172 : process has ended: exit status 1 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f9663423ec0 2016-08-11 12:17:34.632+0000: 43670: debug : virEventRunDefaultImpl:305 : running default event implementation 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7f9663421f20 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollCleanupTimeouts:526 : Cleanup 1 2016-08-11 12:17:34.632+0000: 43669: info : virObjectUnref:261 : OBJECT_DISPOSE: obj=0x7f9663421f20 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollCleanupHandles:575 : Cleanup 1 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollMakePollFDs:401 : Prepare n=0 w=1, f=5 e=1 d=0 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollCalculateTimeout:371 : No timeout is pending 2016-08-11 12:17:34.632+0000: 43670: info : virEventPollRunOnce:641 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2016-08-11 12:17:34.632+0000: 43669: debug : virEventPollInterruptLocked:727 : Interrupting 2016-08-11 12:17:34.632+0000: 43669: info : virEventPollAddTimeout:253 : EVENT_POLL_ADD_TIMEOUT: timer=2 frequency=0 cb=0x7f96620b7ae0 opaque=(nil) ff=(nil) 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollRunOnce:651 : Poll got 1 event(s) 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollDispatchTimeouts:433 : Dispatch 2 2016-08-11 12:17:34.632+0000: 43670: info : virEventPollDispatchTimeouts:456 : EVENT_POLL_DISPATCH_TIMEOUT: timer=2 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollDispatchHandles:479 : Dispatch 1 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollDispatchHandles:493 : i=0 w=1 2016-08-11 12:17:34.632+0000: 43670: info : virEventPollDispatchHandles:507 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollCleanupTimeouts:526 : Cleanup 2 2016-08-11 12:17:34.632+0000: 43670: debug : virEventPollCleanupHandles:575 : Cleanup 1 2016-08-11 12:17:34.632+0000: 43670: debug : virThreadJobClear:124 : Thread 43670 finished job vshEventLoop with ret=0 2016-08-11 12:17:34.632+0000: 43669: info : virEventPollRemoveTimeout:305 : EVENT_POLL_REMOVE_TIMEOUT: timer=2 2016-08-11 12:17:34.632+0000: 43669: debug : virEventPollInterruptLocked:723 : Skip interrupt, 0 140283594831616 2016-08-11 12:17:34.632+0000: 43669: info : virEventPollRemoveTimeout:305 : EVENT_POLL_REMOVE_TIMEOUT: timer=1 2016-08-11 12:17:34.632+0000: 43669: debug : virEventPollInterruptLocked:723 : Skip interrupt, 0 140283594831616