[ovirt-users] Importing VM from Xen Server 6.5

Shahar Havivi shavivi at redhat.com
Thu Aug 11 13:05:46 UTC 2016


On 11.08.16 18:09, Anantha Raghava wrote:
> 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,
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 at 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:
> > On 11.08.16 14:14, Anantha Raghava wrote:
> > > Hi,
> > > 
> > > Tested this with different combinations:
> > > 
> > > a. from VDSM host, both "ssh root at 192.168.1.40" and "sudo -u vdsm ssh
> > > root at 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,
> > 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 at exzatechconsulting.com
> > > <mailto:raghav at 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 at 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 at redhat.com
> > > > > > <mailto:rjones at 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-Transports.html
> > > > > >       <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




More information about the Users mailing list