Attachment 599573 Details for Bug 842114 – Output from LIBVIRT_DEBUG=1

Output from LIBVIRT_DEBUG=1

libvirt-debug.log (text/x-log), 14.69 KB, created by Richard W.M. Jones on 2012-07-22 08:46:16 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Richard W.M. Jones

Created: 2012-07-22 08:46:16 UTC

Size: 14.69 KB

patch

obsolete

>2012-07-22 08:45:28.433+0000: 14694: info : libvirt version: 0.9.13, package: 1.fc18 (Fedora Project, 2012-07-02-06:17:18, )
>2012-07-22 08:45:28.433+0000: 14694: debug : virInitialize:409 : register drivers
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:714 : driver=0x39ee4c2980 name=Test
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:729 : registering Test as driver 0
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterNetworkDriver:546 : registering Test as network driver 0
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterInterfaceDriver:576 : registering Test as interface driver 0
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterStorageDriver:606 : registering Test as storage driver 0
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDeviceMonitor:636 : registering Test as device driver 0
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterSecretDriver:666 : registering Test as secret driver 0
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterNWFilterDriver:696 : registering Test as network filter driver 0
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:714 : driver=0x39ee4c4500 name=OPENVZ
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:729 : registering OPENVZ as driver 1
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:714 : driver=0x39ee4c4a40 name=VMWARE
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:729 : registering VMWARE as driver 2
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:714 : driver=0x39ee4c3dc0 name=PHYP
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:729 : registering PHYP as driver 3
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterStorageDriver:606 : registering PHYP as storage driver 1
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterInterfaceDriver:576 : registering PHYP as interface driver 1
>2012-07-22 08:45:28.433+0000: 14694: debug : vboxRegister:137 : VBoxCGlueInit failed, using dummy driver
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:714 : driver=0x39ee4c4f80 name=VBOX
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:729 : registering VBOX as driver 4
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterNetworkDriver:546 : registering VBOX as network driver 1
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterStorageDriver:606 : registering VBOX as storage driver 2
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:714 : driver=0x39ee4c8040 name=ESX
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterDriver:729 : registering ESX as driver 5
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterInterfaceDriver:576 : registering ESX as interface driver 2
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterNetworkDriver:546 : registering ESX as network driver 2
>2012-07-22 08:45:28.433+0000: 14694: debug : virRegisterStorageDriver:606 : registering ESX as storage driver 3
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterDeviceMonitor:636 : registering ESX as device driver 1
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterSecretDriver:666 : registering ESX as secret driver 1
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterNWFilterDriver:696 : registering ESX as network filter driver 1
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterDriver:714 : driver=0x39ee4c8940 name=Hyper-V
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterDriver:729 : registering Hyper-V as driver 6
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterInterfaceDriver:576 : registering Hyper-V as interface driver 3
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterNetworkDriver:546 : registering Hyper-V as network driver 3
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterStorageDriver:606 : registering Hyper-V as storage driver 4
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterDeviceMonitor:636 : registering Hyper-V as device driver 2
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterSecretDriver:666 : registering Hyper-V as secret driver 2
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterNWFilterDriver:696 : registering Hyper-V as network filter driver 2
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterDriver:714 : driver=0x39ee4c3280 name=remote
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterDriver:729 : registering remote as driver 7
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterNetworkDriver:546 : registering remote as network driver 4
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterInterfaceDriver:576 : registering remote as interface driver 4
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterStorageDriver:606 : registering remote as storage driver 5
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterDeviceMonitor:636 : registering remote as device driver 3
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterSecretDriver:666 : registering remote as secret driver 3
>2012-07-22 08:45:28.434+0000: 14694: debug : virRegisterNWFilterDriver:696 : registering remote as network filter driver 3
>2012-07-22 08:45:28.434+0000: 14694: debug : virEventRegisterDefaultImpl:204 : registering default event implementation
>2012-07-22 08:45:28.434+0000: 14694: debug : virEventPollAddHandle:115 : Used 0 handle slots, adding at least 10 more
>2012-07-22 08:45:28.434+0000: 14694: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 0
>2012-07-22 08:45:28.434+0000: 14694: debug : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=1 fd=4 events=1 cb=0x39ee056870 opaque=(nil) ff=(nil)
>2012-07-22 08:45:28.434+0000: 14694: debug : virEventRegisterImpl:177 : addHandle=0x39ee057380 updateHandle=0x39ee057270 removeHandle=0x39ee056c90 addTimeout=0x39ee056df0 updateTimeout=0x39ee056fc0 removeTimeout=0x39ee0570f0
>2012-07-22 08:45:28.434+0000: 14694: debug : virConnectOpenAuth:1385 : name=(null), auth=0x39ee4c2900, flags=0
>2012-07-22 08:45:28.434+0000: 14695: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-07-22 08:45:28.434+0000: 14695: debug : virEventPollCleanupTimeouts:505 : Cleanup 0
>2012-07-22 08:45:28.434+0000: 14695: debug : virEventPollCleanupTimeouts:541 : Found 0 out of 0 timeout slots used, releasing 0
>2012-07-22 08:45:28.434+0000: 14695: debug : virEventPollCleanupHandles:553 : Cleanup 1
>2012-07-22 08:45:28.434+0000: 14695: debug : virEventPollMakePollFDs:382 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-07-22 08:45:28.434+0000: 14695: debug : virEventPollCalculateTimeout:324 : Calculate expiry of 0 timers
>2012-07-22 08:45:28.434+0000: 14695: debug : virEventPollCalculateTimeout:350 : Timeout at 0 due in -1 ms
>2012-07-22 08:45:28.434+0000: 14695: debug : virEventPollRunOnce:618 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1116 : no name, allowing driver auto-select
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1156 : trying driver 0 (Test) ...
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1162 : driver 0 Test returned DECLINED
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1156 : trying driver 1 (OPENVZ) ...
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1162 : driver 1 OPENVZ returned DECLINED
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1156 : trying driver 2 (VMWARE) ...
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1162 : driver 2 VMWARE returned DECLINED
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1156 : trying driver 3 (PHYP) ...
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1162 : driver 3 PHYP returned DECLINED
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1156 : trying driver 4 (VBOX) ...
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1162 : driver 4 VBOX returned DECLINED
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1156 : trying driver 5 (ESX) ...
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1162 : driver 5 ESX returned DECLINED
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1156 : trying driver 6 (Hyper-V) ...
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1162 : driver 6 Hyper-V returned DECLINED
>2012-07-22 08:45:28.436+0000: 14694: debug : do_open:1156 : trying driver 7 (remote) ...
>2012-07-22 08:45:28.436+0000: 14694: debug : remoteOpen:865 : Auto-probe remote URI
>2012-07-22 08:45:28.436+0000: 14694: debug : remoteOpen:868 : Auto-spawn user daemon instance
>2012-07-22 08:45:28.436+0000: 14694: debug : doRemoteOpen:542 : proceeding with name = 
>2012-07-22 08:45:28.436+0000: 14694: debug : doRemoteOpen:552 : Connecting with transport 1
>2012-07-22 08:45:28.436+0000: 14694: debug : doRemoteOpen:599 : Proceeding with sockname /run/user/1000/libvirt/libvirt-sock
>2012-07-22 08:45:28.436+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:28.436+0000: 14694: debug : virCommandRunAsync:2182 : About to run LC_ALL=C PATH=/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/home/rjones/.local/bin:/home/rjones/bin HOME=/home/rjones USER=rjones LOGNAME=rjones /usr/sbin/libvirtd --timeout=30
>2012-07-22 08:45:28.439+0000: 14694: debug : virFileClose:70 : Closed fd 7
>2012-07-22 08:45:28.439+0000: 14694: debug : virCommandRunAsync:2200 : Command result 0, with PID 14696
>2012-07-22 08:45:28.439+0000: 14696: debug : virFileClose:70 : Closed fd 3
>2012-07-22 08:45:28.469+0000: 14696: debug : virFileClose:70 : Closed fd 4
>2012-07-22 08:45:28.469+0000: 14696: debug : virFileClose:70 : Closed fd 5
>2012-07-22 08:45:28.469+0000: 14696: debug : virFileClose:70 : Closed fd 6
>2012-07-22 08:45:28.518+0000: 14694: debug : virCommandRun:1998 : Result status 0, stdout: '(null)' stderr: '(null)'
>2012-07-22 08:45:28.618+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:28.818+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:29.119+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:29.519+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:30.019+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:30.619+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:31.319+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:32.120+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:33.020+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:34.020+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:35.121+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:36.321+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:37.621+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:39.022+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:40.522+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:42.122+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:43.823+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:45.623+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:47.523+0000: 14694: debug : virNetSocketNewConnectUNIX:509 : Connection refused for /run/user/1000/libvirt/libvirt-sock, trying to spawn /usr/sbin/libvirtd
>2012-07-22 08:45:49.525+0000: 14694: debug : virFileClose:70 : Closed fd 6
>2012-07-22 08:45:49.525+0000: 14694: debug : virNetClientClose:526 : client=(nil)
>2012-07-22 08:45:49.525+0000: 14694: debug : do_open:1162 : driver 7 remote returned ERROR
>2012-07-22 08:45:49.525+0000: 14694: debug : virUnrefConnect:145 : unref connection 0x23567c0 1
>2012-07-22 08:45:49.525+0000: 14694: debug : virReleaseConnect:94 : release connection 0x23567c0
>error: Failed to reconnect to the hypervisor
>error: no valid connection
>error: Failed to connect socket to '/run/user/1000/libvirt/libvirt-sock': No such file or directory
>2012-07-22 08:45:49.533+0000: 14694: debug : virEventPollAddTimeout:224 : Used 0 timeout slots, adding at least 10 more
>2012-07-22 08:45:49.533+0000: 14694: debug : virEventPollInterruptLocked:705 : Interrupting
>2012-07-22 08:45:49.533+0000: 14694: debug : virEventPollAddTimeout:247 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=0 cb=0x40bf20 opaque=(nil) ff=(nil)
>2012-07-22 08:45:49.533+0000: 14695: debug : virEventPollRunOnce:629 : Poll got 1 event(s)
>2012-07-22 08:45:49.533+0000: 14695: debug : virEventPollDispatchTimeouts:414 : Dispatch 1
>2012-07-22 08:45:49.533+0000: 14695: debug : virEventPollDispatchTimeouts:437 : EVENT_POLL_DISPATCH_TIMEOUT: timer=1
>2012-07-22 08:45:49.533+0000: 14695: debug : virEventPollDispatchHandles:459 : Dispatch 1
>2012-07-22 08:45:49.533+0000: 14695: debug : virEventPollDispatchHandles:473 : i=0 w=1
>2012-07-22 08:45:49.533+0000: 14695: debug : virEventPollDispatchHandles:487 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-07-22 08:45:49.533+0000: 14695: debug : virEventPollCleanupTimeouts:505 : Cleanup 1
>2012-07-22 08:45:49.533+0000: 14695: debug : virEventPollCleanupHandles:553 : Cleanup 1
>2012-07-22 08:45:49.533+0000: 14694: debug : virEventPollRemoveTimeout:292 : EVENT_POLL_REMOVE_TIMEOUT: timer=1
>2012-07-22 08:45:49.533+0000: 14694: debug : virEventPollInterruptLocked:701 : Skip interrupt, 0 -1688688896
>

Actions: View

Attachments on bug 842114: 599573