[libvirt-users] "virsh list" ahngs
Yunchih Chen
yunchih at csie.ntu.edu.tw
Fri Feb 17 16:21:31 UTC 2017
`virsh list` hangs on my server that hosts a bunch of VMs.
This might be due to the Debian upgrade I did on Feb 15, which upgrades
`libvirt` from 2.4.0-1 to 3.0.0-2.
I have tried restarting libvirtd for a few times, without luck.
Attached below are some relevant logs; let me know if you need some more
for debugging.
Thanks for your help!!
root at vm-host:~# uname -a
Linux vm-host 4.6.0-1-amd64 #1 SMP Debian 4.6.4-1 (2016-07-18) x86_64
GNU/Linux
root at vm-host:~# apt-cache policy libvirt-daemon
libvirt-daemon:
Installed: 3.0.0-2
Candidate: 3.0.0-2
Version table:
*** 3.0.0-2 500
500 http://debian.csie.ntu.edu.tw/debian testing/main amd64
Packages
100 /var/lib/dpkg/status
root at vm-host:~# strace -o /tmp/trace -e trace=network,file,poll virsh
list # hangs forever .....
^C
root at vm-host:~# tail -10 /tmp/trace
access("/etc/libvirt/libvirt.conf", F_OK) = 0
open("/etc/libvirt/libvirt.conf", O_RDONLY) = 5
access("/proc/vz", F_OK) = -1 ENOENT (No such file or
directory)
socket(AF_UNIX, SOCK_STREAM, 0) = 5
connect(5, {sa_family=AF_UNIX,
sun_path="/var/run/libvirt/libvirt-sock"}, 110) = 0
getsockname(5, {sa_family=AF_UNIX}, [128->2]) = 0
poll([{fd=5, events=POLLOUT}, {fd=6, events=POLLIN}], 2, -1) = 1
([{fd=5, revents=POLLOUT}])
poll([{fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 2, -1) = ?
ERESTART_RESTARTBLOCK (Interrupted by signal)
--- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
+++ killed by SIGINT +++
root at vm-host:~# lsof /var/run/libvirt/libvirt-sock # hangs too ...
^C
root at vm-host:~# LIBVIRT_DEBUG=1 virsh list
2017-02-17 15:58:36.126+0000: 18505: info : libvirt version: 3.0.0,
package: 2 (Guido Günther <agx at sigxcpu.org> Wed, 25 Jan 2017 07:04:08
+0100)
2017-02-17 15:58:36.126+0000: 18505: info : hostname: vm-host
2017-02-17 15:58:36.126+0000: 18505: debug : virGlobalInit:386 :
register drivers
2017-02-17 15:58:36.127+0000: 18505: debug :
virRegisterConnectDriver:684 : driver=0x7f1e5aca2c40 name=Test
2017-02-17 15:58:36.127+0000: 18505: debug :
virRegisterConnectDriver:695 : registering Test as driver 0
2017-02-17 15:58:36.127+0000: 18505: debug :
virRegisterConnectDriver:684 : driver=0x7f1e5aca4ac0 name=OPENVZ
2017-02-17 15:58:36.127+0000: 18505: debug :
virRegisterConnectDriver:695 : registering OPENVZ as driver 1
2017-02-17 15:58:36.127+0000: 18505: debug :
virRegisterConnectDriver:684 : driver=0x7f1e5aca5260 name=VMWARE
2017-02-17 15:58:36.127+0000: 18505: debug :
virRegisterConnectDriver:695 : registering VMWARE as driver 2
2017-02-17 15:58:36.127+0000: 18505: debug :
virRegisterConnectDriver:684 : driver=0x7f1e5aca3720 name=remote
2017-02-17 15:58:36.127+0000: 18505: debug :
virRegisterConnectDriver:695 : registering remote as driver 3
2017-02-17 15:58:36.127+0000: 18505: debug :
virEventRegisterDefaultImpl:267 : registering default event implementation
2017-02-17 15:58:36.127+0000: 18505: debug : virEventPollAddHandle:115 :
Used 0 handle slots, adding at least 10 more
2017-02-17 15:58:36.127+0000: 18505: debug :
virEventPollInterruptLocked:722 : Skip interrupt, 0 0
2017-02-17 15:58:36.127+0000: 18505: info : virEventPollAddHandle:140 :
EVENT_POLL_ADD_HANDLE: watch=1 fd=3 events=1 cb=0x7f1e5a7fc140
opaque=(nil) ff=(nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virEventRegisterImpl:234 :
addHandle=0x7f1e5a7fc860 updateHandle=0x7f1e5a7fcb90
removeHandle=0x7f1e5a7fc1a0 addTimeout=0x7f1e5a7fc310
updateTimeout=0x7f1e5a7fc510 removeTimeout=0x7f1e5a7fc6e0
2017-02-17 15:58:36.127+0000: 18505: debug : virEventPollAddTimeout:230
: Used 0 timeout slots, adding at least 10 more
2017-02-17 15:58:36.127+0000: 18505: debug :
virEventPollInterruptLocked:722 : Skip interrupt, 0 0
2017-02-17 15:58:36.127+0000: 18505: info : virEventPollAddTimeout:253 :
EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=-1 cb=0x563a29758360
opaque=0x7fff70941380 ff=(nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenAuth:1245 :
name=<null>, auth=0x7f1e5aca2a00, flags=0
2017-02-17 15:58:36.127+0000: 18505: info : virObjectNew:202 :
OBJECT_NEW: obj=0x563a2a7f5f50 classname=virConnect
2017-02-17 15:58:36.127+0000: 18505: debug : virConfLoadConfig:1604 :
Loading config file '/etc/libvirt/libvirt.conf'
2017-02-17 15:58:36.127+0000: 18505: debug : virConfReadFile:778 :
filename=/etc/libvirt/libvirt.conf
2017-02-17 15:58:36.127+0000: 18506: debug : virThreadJobSet:99 : Thread
18506 is now running job vshEventLoop
2017-02-17 15:58:36.127+0000: 18506: debug : virEventRunDefaultImpl:311
: running default event implementation
2017-02-17 15:58:36.127+0000: 18505: debug : virFileClose:108 : Closed fd 5
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupTimeouts:525 : Cleanup 1
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupHandles:574 : Cleanup 1
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18506: debug : virEventPollMakePollFDs:401
: Prepare n=0 w=1, f=3 e=1 d=0
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2017-02-17 15:58:36.127+0000: 18506: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=1 timeout=-1
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfAddEntry:241 : Add
entry (null) (nil)
2017-02-17 15:58:36.127+0000: 18505: debug : virConfGetValueString:932 :
Get value string (nil) 0
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenInternal:1040
: no name, allowing driver auto-select
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenInternal:1083
: trying driver 0 (Test) ...
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenInternal:1098
: driver 0 Test returned DECLINED
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenInternal:1083
: trying driver 1 (OPENVZ) ...
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenInternal:1098
: driver 1 OPENVZ returned DECLINED
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenInternal:1083
: trying driver 2 (VMWARE) ...
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenInternal:1098
: driver 2 VMWARE returned DECLINED
2017-02-17 15:58:36.127+0000: 18505: debug : virConnectOpenInternal:1083
: trying driver 3 (remote) ...
2017-02-17 15:58:36.127+0000: 18505: debug : remoteConnectOpen:1343 :
Auto-probe remote URI
2017-02-17 15:58:36.127+0000: 18505: debug : doRemoteOpen:907 :
proceeding with name =
2017-02-17 15:58:36.127+0000: 18505: debug : doRemoteOpen:916 :
Connecting with transport 1
2017-02-17 15:58:36.127+0000: 18505: debug : doRemoteOpen:1051 :
Proceeding with sockname /var/run/libvirt/libvirt-sock
2017-02-17 15:58:36.127+0000: 18505: debug :
virNetSocketNewConnectUNIX:639 : path=/var/run/libvirt/libvirt-sock
spawnDaemon=0 binary=<null>
2017-02-17 15:58:36.127+0000: 18505: debug :
virNetSocketNewConnectUNIX:703 : connect() succeeded
2017-02-17 15:58:36.127+0000: 18505: debug : virNetSocketNew:235 :
localAddr=0x7fff70940d00 remoteAddr=0x7fff70940d90 fd=5 errfd=-1 pid=0
2017-02-17 15:58:36.127+0000: 18505: info : virObjectNew:202 :
OBJECT_NEW: obj=0x563a2a7f7980 classname=virNetSocket
2017-02-17 15:58:36.127+0000: 18505: info : virNetSocketNew:291 :
RPC_SOCKET_NEW: sock=0x563a2a7f7980 fd=5 errfd=-1 pid=0
localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0
2017-02-17 15:58:36.127+0000: 18505: info : virObjectNew:202 :
OBJECT_NEW: obj=0x563a2a7f7d80 classname=virNetClient
2017-02-17 15:58:36.127+0000: 18505: info : virNetClientNew:328 :
RPC_CLIENT_NEW: client=0x563a2a7f7d80 sock=0x563a2a7f7980
2017-02-17 15:58:36.127+0000: 18505: info : virObjectRef:296 :
OBJECT_REF: obj=0x563a2a7f7d80
2017-02-17 15:58:36.127+0000: 18505: info : virObjectRef:296 :
OBJECT_REF: obj=0x563a2a7f7980
2017-02-17 15:58:36.127+0000: 18505: debug :
virEventPollInterruptLocked:726 : Interrupting
2017-02-17 15:58:36.127+0000: 18505: info : virEventPollAddHandle:140 :
EVENT_POLL_ADD_HANDLE: watch=2 fd=5 events=1 cb=0x7f1e5a96cd10
opaque=0x563a2a7f7980 ff=0x7f1e5a96ccc0
2017-02-17 15:58:36.127+0000: 18505: debug : virKeepAliveNew:199 :
client=0x563a2a7f7d80, interval=-1, count=0
2017-02-17 15:58:36.127+0000: 18505: info : virObjectNew:202 :
OBJECT_NEW: obj=0x563a2a7f8080 classname=virKeepAlive
2017-02-17 15:58:36.127+0000: 18505: info : virKeepAliveNew:218 :
RPC_KEEPALIVE_NEW: ka=0x563a2a7f8080 client=0x563a2a7f7d80
2017-02-17 15:58:36.127+0000: 18505: info : virObjectRef:296 :
OBJECT_REF: obj=0x563a2a7f7d80
2017-02-17 15:58:36.127+0000: 18505: info : virObjectNew:202 :
OBJECT_NEW: obj=0x563a2a7f6740 classname=virConnectCloseCallbackData
2017-02-17 15:58:36.127+0000: 18506: debug : virEventPollRunOnce:650 :
Poll got 1 event(s)
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollDispatchTimeouts:432 : Dispatch 1
2017-02-17 15:58:36.127+0000: 18505: info : virObjectRef:296 :
OBJECT_REF: obj=0x563a2a7f6740
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollDispatchHandles:478 : Dispatch 1
2017-02-17 15:58:36.127+0000: 18505: info : virObjectNew:202 :
OBJECT_NEW: obj=0x563a2a7f7fa0 classname=virNetClientProgram
2017-02-17 15:58:36.127+0000: 18505: info : virObjectNew:202 :
OBJECT_NEW: obj=0x563a2a7f7b60 classname=virNetClientProgram
2017-02-17 15:58:36.127+0000: 18505: info : virObjectNew:202 :
OBJECT_NEW: obj=0x563a2a7f7910 classname=virNetClientProgram
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollDispatchHandles:492 : i=0 w=1
2017-02-17 15:58:36.127+0000: 18505: info : virObjectRef:296 :
OBJECT_REF: obj=0x563a2a7f7fa0
2017-02-17 15:58:36.127+0000: 18506: info :
virEventPollDispatchHandles:506 : EVENT_POLL_DISPATCH_HANDLE: watch=1
events=1
2017-02-17 15:58:36.127+0000: 18505: info : virObjectRef:296 :
OBJECT_REF: obj=0x563a2a7f7b60
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupTimeouts:525 : Cleanup 1
2017-02-17 15:58:36.127+0000: 18505: info : virObjectRef:296 :
OBJECT_REF: obj=0x563a2a7f7910
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupHandles:574 : Cleanup 2
2017-02-17 15:58:36.127+0000: 18505: debug : doRemoteOpen:1170 : Trying
authentication
2017-02-17 15:58:36.127+0000: 18506: debug : virEventRunDefaultImpl:311
: running default event implementation
2017-02-17 15:58:36.127+0000: 18505: debug : virNetMessageNew:46 :
msg=0x563a2a7fa470 tracked=0
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupTimeouts:525 : Cleanup 1
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupHandles:574 : Cleanup 2
2017-02-17 15:58:36.127+0000: 18506: debug : virEventPollMakePollFDs:401
: Prepare n=0 w=1, f=3 e=1 d=0
2017-02-17 15:58:36.127+0000: 18505: debug :
virNetMessageEncodePayload:386 : Encode length as 28
2017-02-17 15:58:36.127+0000: 18506: debug : virEventPollMakePollFDs:401
: Prepare n=1 w=2, f=5 e=1 d=0
2017-02-17 15:58:36.127+0000: 18505: info :
virNetClientSendInternal:2104 : RPC_CLIENT_MSG_TX_QUEUE:
client=0x563a2a7f7d80 len=28 prog=536903814 vers=1 proc=66 type=0
status=0 serial=0
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2017-02-17 15:58:36.127+0000: 18505: debug : virNetClientCallNew:2057 :
New call 0x563a2a7f7340: msg=0x563a2a7fa470, expectReply=1, nonBlock=0
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2017-02-17 15:58:36.127+0000: 18505: debug : virNetClientIO:1866 :
Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0
length=28 dispatch=(nil)
2017-02-17 15:58:36.127+0000: 18506: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=2 timeout=-1
2017-02-17 15:58:36.127+0000: 18505: debug : virNetClientIO:1925 : We
have the buck head=0x563a2a7f7340 call=0x563a2a7f7340
2017-02-17 15:58:36.127+0000: 18505: info : virEventPollUpdateHandle:152
: EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2017-02-17 15:58:36.127+0000: 18505: debug :
virEventPollInterruptLocked:726 : Interrupting
2017-02-17 15:58:36.127+0000: 18506: debug : virEventPollRunOnce:650 :
Poll got 1 event(s)
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollDispatchTimeouts:432 : Dispatch 1
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollDispatchHandles:478 : Dispatch 2
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollDispatchHandles:492 : i=0 w=1
2017-02-17 15:58:36.127+0000: 18506: info :
virEventPollDispatchHandles:506 : EVENT_POLL_DISPATCH_HANDLE: watch=1
events=1
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupTimeouts:525 : Cleanup 1
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupHandles:574 : Cleanup 2
2017-02-17 15:58:36.127+0000: 18506: debug : virEventRunDefaultImpl:311
: running default event implementation
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupTimeouts:525 : Cleanup 1
2017-02-17 15:58:36.127+0000: 18506: debug :
virEventPollCleanupHandles:574 : Cleanup 2
2017-02-17 15:58:36.127+0000: 18506: debug : virEventPollMakePollFDs:401
: Prepare n=0 w=1, f=3 e=1 d=0
2017-02-17 15:58:36.127+0000: 18506: debug : virEventPollMakePollFDs:401
: Prepare n=1 w=2, f=5 e=0 d=0
2017-02-17 15:58:36.128+0000: 18506: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2017-02-17 15:58:36.128+0000: 18506: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2017-02-17 15:58:36.128+0000: 18506: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=1 timeout=-1
^C
--
--
Yun-Chih Chen 陳耘志
Network/Workstation Assistant
Dept. of Computer Science and Information Engineering
National Taiwan University
Tel: +886-2-33664888 ext. 217/204
Email: ta217 at csie.ntu.edu.tw
Website: http://wslab.csie.ntu.edu.tw/
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/libvirt-users/attachments/20170218/b8cd8355/attachment.htm>
More information about the libvirt-users
mailing list