1061654 – libvirtd hangs in virDomainCreateXML

Bug 1061654 - libvirtd hangs in virDomainCreateXML

Summary: libvirtd hangs in virDomainCreateXML

Keywords:
Status:	CLOSED NOTABUG
Alias:	None
Product:	Virtualization Tools
Classification:	Community
Component:	libvirt
Sub Component:
Version:	unspecified
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	---
Assignee:	Libvirt Maintainers
QA Contact:
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	TRACKER-bugs-affecting-libguestfs
TreeView+	depends on / blocked

Reported:	2014-02-05 10:34 UTC by Richard W.M. Jones
Modified:	2014-02-05 10:45 UTC (History)
CC List:	3 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2014-02-05 10:45:31 UTC
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Description Richard W.M. Jones 2014-02-05 10:34:21 UTC

Description of problem:

libvirtd in current rawhide hangs almost 100% of the time in
virDomainCreateXML, meaning that no transient guests can be
created.

Version-Release number of selected component (if applicable):

libvirt 1.2.1-2.fc21.x86_64

How reproducible:

Nearly 100%

Steps to Reproduce:
1. Run libguestfs-test-tool
2.
3.

Actual results:

Hangs at:

libguestfs: [02683ms] launch libvirt guest

Expected results:

Should not hang.

Additional info:

Stack trace inside libvirtd is:

(gdb) t a a bt

Thread 11 (Thread 0x7fab41233700 (LWP 13537)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706d20, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c720b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d60) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 10 (Thread 0x7fab40a32700 (LWP 13538)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706d20, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c720b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705c10) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 9 (Thread 0x7fab40231700 (LWP 13539)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706d20, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c720b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d60) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 8 (Thread 0x7fab3fa30700 (LWP 13540)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706d20, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c720b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d80) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
---Type <return> to continue, or q <return> to quit---
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 7 (Thread 0x7fab3f22f700 (LWP 13541)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706d20, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c720b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d60) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 6 (Thread 0x7fab3ea2e700 (LWP 13542)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706db8, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c722b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d80) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 5 (Thread 0x7fab3e22d700 (LWP 13543)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706db8, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c722b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d60) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 4 (Thread 0x7fab3da2c700 (LWP 13544)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706db8, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c722b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d80) at util/virthreadpool.c:103
---Type <return> to continue, or q <return> to quit---
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 3 (Thread 0x7fab3d22b700 (LWP 13545)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706db8, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c722b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d60) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 2 (Thread 0x7fab3ca2a700 (LWP 13546)):
#0  0x00007fab47b17320 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib64/libpthread.so.0
#1  0x00007fab4a8c6d56 in virCondWait (c=c@entry=0x7fab4c706db8, 
    m=m@entry=0x7fab4c706cf8) at util/virthreadpthread.c:117
#2  0x00007fab4a8c722b in virThreadPoolWorker (
    opaque=opaque@entry=0x7fab4c705d80) at util/virthreadpool.c:103
#3  0x00007fab4a8c6b7e in virThreadHelper (data=<optimized out>)
    at util/virthreadpthread.c:161
#4  0x00007fab47b13183 in start_thread () from /lib64/libpthread.so.0
#5  0x00007fab4743944d in clone () from /lib64/libc.so.6

Thread 1 (Thread 0x7fab4b3a5880 (LWP 13535)):
#0  0x00007fab4742f07d in poll () from /lib64/libc.so.6
#1  0x00007fab4a899157 in poll (__timeout=-1, __nfds=10, __fds=<optimized out>)
    at /usr/include/bits/poll2.h:46
#2  virEventPollRunOnce () at util/vireventpoll.c:631
#3  0x00007fab4a897c9d in virEventRunDefaultImpl () at util/virevent.c:306
#4  0x00007fab4a9b7b0d in virNetServerRun (srv=0x7fab4c706bb0)
    at rpc/virnetserver.c:1112
#5  0x00007fab4b3f4d0f in main (argc=<optimized out>, argv=<optimized out>)
    at libvirtd.c:1517

Comment 1 Richard W.M. Jones 2014-02-05 10:36:10 UTC

Hmm, maybe this is actually qemu which is broken.

I notice there is a qemu process which is consuming CPU but not
proceeding anywhere.

$ ps ax | grep qemu
13673 ?        Sl     4:15 /usr/bin/qemu-system-x86_64 -name guestfs-8jzjfp15twxg0yil -S -machine pc-i440fx-1.7,accel=tcg,usb=off -m 500 -realtime mlock=off -smp 1,sockets=1,cores=1,threads=1 -uuid ab2bbfd9-4cd2-4c30-b220-42d409ccc298 -nographic -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/home/rjones/.config/libvirt/qemu/lib/guestfs-8jzjfp15twxg0yil.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew -global kvm-pit.lost_tick_policy=discard -no-hpet -no-reboot -no-acpi -boot strict=on -kernel /home/rjones/d/libguestfs/tmp/.guestfs-1000/kernel.13471 -initrd /home/rjones/d/libguestfs/tmp/.guestfs-1000/initrd.13471 -append panic=1 console=ttyS0 udevtimeout=600 no_timer_check lpj=3411128 acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x2 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x3 -drive file=/home/rjones/d/libguestfs/tmp/libguestfs1kzChX/scratch.1,if=none,id=drive-scsi0-0-0-0,format=raw,cache=unsafe -device scsi-hd,bus=scsi0.0,channel=0,scsi-id=0,lun=0,drive=drive-scsi0-0-0-0,id=scsi0-0-0-0,bootindex=1 -drive file=/home/rjones/d/libguestfs/tmp/libguestfs1kzChX/overlay2,if=none,id=drive-scsi0-0-1-0,format=qcow2,cache=unsafe -device scsi-hd,bus=scsi0.0,channel=0,scsi-id=1,lun=0,drive=drive-scsi0-0-1-0,id=scsi0-0-1-0 -chardev socket,id=charserial0,path=/home/rjones/d/libguestfs/tmp/libguestfs1kzChX/console.sock -device isa-serial,chardev=charserial0,id=serial0 -chardev socket,id=charchannel0,path=/home/rjones/d/libguestfs/tmp/libguestfs1kzChX/guestfsd.sock -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=org.libguestfs.channel.0 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x4

Comment 2 Daniel Berrangé 2014-02-05 10:42:08 UTC

The libvirtd stack trace doesn't show any signs of trouble. Any time you see the virThreadPoolWorker function blocked on  virCondWait this indicates that libvirtd thread is idle waiting for an API request. The primary thread looks normal too, waiting in poll for socket I/O

Comment 3 Richard W.M. Jones 2014-02-05 10:45:18 UTC

OK forget it.  This turns out to be the kernel hanging bug:

http://rawhidewatch.wordpress.com/2014/02/04/boot-failures-with-recent-rawhide-kernels/

Note You need to log in before you can comment on or make changes to this bug.