[libvirt] crash in libvirtd when assigning PCI device (storage controller)
Compiled libvirt and friends from todays sources on ubuntu 9.10. Was playing around with vt-d and while my MB works fine with ESXi 4, I got some permission issues when I tried the KVM and virt-manager included from ubuntu so I just gambled and compiled everything from latest sources. Things seems to work fine in a normal use case, but if I a PCI device such as a storage controller, libvirtd will get a sigsev. I got the onboard Intel Sata, a PCI Sil Sata card as well as an Areca Raid controller in this machine. I have not tried the Intel Sata device as I am booting from that, but both the other devices causes sigsev. I am sure assigned an intel network card a bit earlier and it actually worked (well, the VM started to boot at least and entered win7 installation without libvirtd crashing), but when I tested that again now, seems like the ethernet card causes the same problem. It is 6AM so will not do a serious attempt at debugging this, just wanted to check if anyone had an idea before I spent more time potentially debugging stuff that is know to not work.
From dmesg:
[ 986.341633] device vnet0 entered promiscuous mode [ 986.342897] virbr0: topology change detected, propagating [ 986.342902] virbr0: port 1(vnet0) entering forwarding state [ 986.380733] pci-stub 0000:09:01.0: enabling device (0000 -> 0003) [ 986.380786] pci-stub 0000:09:01.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22 [ 986.422128] pci-stub 0000:09:01.0: restoring config space at offset 0x9 (was 0x0, writing 0xe3c04000) [ 986.422141] pci-stub 0000:09:01.0: restoring config space at offset 0x8 (was 0x1, writing 0x1041) [ 986.422152] pci-stub 0000:09:01.0: restoring config space at offset 0x7 (was 0x1, writing 0x1061) [ 986.422163] pci-stub 0000:09:01.0: restoring config space at offset 0x6 (was 0x1, writing 0x1051) [ 986.422174] pci-stub 0000:09:01.0: restoring config space at offset 0x5 (was 0x1, writing 0x1065) [ 986.422185] pci-stub 0000:09:01.0: restoring config space at offset 0x4 (was 0x1, writing 0x1059) [ 986.422199] pci-stub 0000:09:01.0: restoring config space at offset 0x1 (was 0x2b00000, writing 0x2b00003) [ 987.172975] assign device: host bdf = 9:1:0 [ 987.173054] deassign device: host bdf = 9:1:0 [ 987.206121] pci-stub 0000:09:01.0: restoring config space at offset 0x9 (was 0x0, writing 0xe3c04000) [ 987.206134] pci-stub 0000:09:01.0: restoring config space at offset 0x8 (was 0x1, writing 0x1041) [ 987.206146] pci-stub 0000:09:01.0: restoring config space at offset 0x7 (was 0x1, writing 0x1061) [ 987.206157] pci-stub 0000:09:01.0: restoring config space at offset 0x6 (was 0x1, writing 0x1051) [ 987.206167] pci-stub 0000:09:01.0: restoring config space at offset 0x5 (was 0x1, writing 0x1065) [ 987.206178] pci-stub 0000:09:01.0: restoring config space at offset 0x4 (was 0x1, writing 0x1059) [ 987.206192] pci-stub 0000:09:01.0: restoring config space at offset 0x1 (was 0x2b00000, writing 0x2b00003) [ 987.206225] pci-stub 0000:09:01.0: PCI INT A disabled [ 987.286791] libvirtd[3193]: segfault at 10 ip 00007f921b4546b4 sp 00007f9216e165e0 error 4 in libpthread-2.10.1.so[7f921b44a000+17000]
From GDB
06:45:32.434: error : qemuMonitorCommandWithHandler:290 : cannot send monitor command 'info cpus': Connection reset by peer 06:45:32.434: error : qemuMonitorTextGetCPUInfo:436 : internal error cannot run monitor command to fetch CPU thread info Program received signal SIGSEGV, Segmentation fault. [Switching to Thread 0x7f485bfff910 (LWP 18120)] 0x00007f48657fb6b4 in pthread_mutex_unlock () from /lib/libpthread.so.0 (gdb) bt #0 0x00007f48657fb6b4 in pthread_mutex_unlock () from /lib/libpthread.so.0 #1 0x0000000000431101 in qemuDomainObjExitMonitorWithDriver (driver=0x11f0110, obj=0x12114f0) at qemu/qemu_driver.c:318 #2 0x000000000043f436 in qemudStartVMDaemon (conn=<value optimized out>, driver=0x11f0110, vm=0x12114f0, migrateFrom=<value optimized out>, stdin_fd=<value optimized out>) at qemu/qemu_driver.c:2320 #3 0x00000000004407c4 in qemudDomainStart (dom=0x11f0330) at qemu/qemu_driver.c:4370 #4 0x00007f4865a621e7 in virDomainCreate (domain=0x11f0330) at libvirt.c:4509 #5 0x0000000000420d68 in remoteDispatchDomainCreate (server=<value optimized out>, client=<value optimized out>, conn=0x1219da0, hdr=<value optimized out>, rerr=0x7f485bffedf0, args=<value optimized out>, ret=0x7f485bffeed0) at remote.c:853 #6 0x00000000004228e1 in remoteDispatchClientCall (server=<value optimized out>, client=0x7f485c000d30, msg=0x7f485c080f00) at dispatch.c:506 #7 0x0000000000422c93 in remoteDispatchClientRequest (server=0x11e2790, client=0x7f485c000d30, msg=0x7f485c080f00) at dispatch.c:388 #8 0x000000000041625c in qemudWorker (data=<value optimized out>) at libvirtd.c:1518 #9 0x00007f48657f7a04 in start_thread () from /lib/libpthread.so.0 #10 0x00007f48655617bd in clone () from /lib/libc.so.6 #11 0x0000000000000000 in ?? () (gdb) select 2 (gdb) info locals argv = 0x0 tmp = <value optimized out> progenv = 0x0 i = 1 ret = 1 sb = {st_dev = 64512, st_ino = 140307, st_nlink = 1, st_mode = 33261, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 2293664, st_blksize = 4096, st_blocks = 4480, st_atim = {tv_sec = 1258937087, tv_nsec = 967226499}, st_mtim = { tv_sec = 1257180462, tv_nsec = 0}, st_ctim = {tv_sec = 1258886336, tv_nsec = 104908677}, __unused = {0, 0, 0}} tapfds = 0x0 ntapfds = 1 qemuCmdFlags = 9436542 keepfd = {fds_bits = {262144, 0 <repeats 15 times>}} emulator = <value optimized out> child = 18145 pos = <value optimized out> ebuf = "\220v\036\001\000\000\000\000\060|WeH\177\000\000(\000\000\000\060\000\000\000\000\354\377[H\177\000\000@\353\377[H\177\000\000`\351\377[H\177\000\000\377\377\377\377H\177\000\000\233\017\037\001\000\000\000\000\326\063G\000\000\000\000\000@\247~eH\177\000\000\200\307OeH\177\000\000\240\306OeH\177\000\000JST\000\071\000\000\000\300\352\377[H\177\000\000\342\000\000\000\000\000\000\000\342\000\000\000\000\000\000\000\273\340G\000\000\000\000\000\300\352\377[H\177\000\000K\000\000\000\000\000\000\000`\351\377[H\177\000\000@\354\377[H\177\000\000P\352\377[H\177\000\000\001\000\000\000\000\000\000\000\320\352\377[H\177\000\000$\000\000\000\000\000\000\000py\255eH\177\000\000@\354\377[H\177\000\000\060|WeH\177\000\000\001\200\255\373\000\000\000\000\260\351\377[H\177\000\000\220\354\377[H\177\000\000\240\352\377["... pidfile = 0x0 logfile = 15 hookData = {conn = 0x1219da0, vm = 0x12114f0, driver = 0x11f0110} __FUNCTION__ = "qemudStartVMDaemon" __func__ = "qemudStartVMDaemon" line 318 is static void qemuDomainObjExitMonitorWithDriver(struct qemud_driver *driver, virDomainObjPtr obj) { qemuDomainObjPrivatePtr priv = obj->privateData; qemuMonitorUnlock(priv->mon); <---- 318 qemuDriverLock(driver); virDomainObjLock(obj); } Yep, not a very good attempt at debugging, but this is the first time I look at this code and I am overdue for Zzzzz :) Regards, Terje _________________________________________________________________ Windows Live: Keep your friends up to date with what you do online. http://www.microsoft.com/middleeast/windows/windowslive/see-it-in-action/soc...
On Mon, Nov 23, 2009 at 10:08:17PM +0000, Terje Marthinussen wrote:
[ 987.286791] libvirtd[3193]: segfault at 10 ip 00007f921b4546b4 sp 00007f9216e165e0 error 4 in libpthread-2.10.1.so[7f921b44a000+17000]
Ok, so this is the libvirtd daemon crash
From GDB
06:45:32.434: error : qemuMonitorCommandWithHandler:290 : cannot send monitor command 'info cpus': Connection reset by peer
Interestingly this suggests that QEMU itself had quit/crashed during startup. You can check /var/log/libvirt/qemu//$GUESTNAME.log to find out what problem QEMU itself had. For whatever reason, this seems to then trigger the libvirtd crash
06:45:32.434: error : qemuMonitorTextGetCPUInfo:436 : internal error cannot run monitor command to fetch CPU thread info
Program received signal SIGSEGV, Segmentation fault. [Switching to Thread 0x7f485bfff910 (LWP 18120)] 0x00007f48657fb6b4 in pthread_mutex_unlock () from /lib/libpthread.so.0 (gdb) bt #0 0x00007f48657fb6b4 in pthread_mutex_unlock () from /lib/libpthread.so.0 #1 0x0000000000431101 in qemuDomainObjExitMonitorWithDriver (driver=0x11f0110, obj=0x12114f0) at qemu/qemu_driver.c:318 #2 0x000000000043f436 in qemudStartVMDaemon (conn=<value optimized out>, driver=0x11f0110, vm=0x12114f0, migrateFrom=<value optimized out>, stdin_fd=<value optimized out>) at qemu/qemu_driver.c:2320 #3 0x00000000004407c4 in qemudDomainStart (dom=0x11f0330) at qemu/qemu_driver.c:4370 #4 0x00007f4865a621e7 in virDomainCreate (domain=0x11f0330) at libvirt.c:4509 #5 0x0000000000420d68 in remoteDispatchDomainCreate (server=<value optimized out>, client=<value optimized out>, conn=0x1219da0, hdr=<value optimized out>, rerr=0x7f485bffedf0, args=<value optimized out>, ret=0x7f485bffeed0) at remote.c:853 #6 0x00000000004228e1 in remoteDispatchClientCall (server=<value optimized out>, client=0x7f485c000d30, msg=0x7f485c080f00) at dispatch.c:506 #7 0x0000000000422c93 in remoteDispatchClientRequest (server=0x11e2790, client=0x7f485c000d30, msg=0x7f485c080f00) at dispatch.c:388 #8 0x000000000041625c in qemudWorker (data=<value optimized out>) at libvirtd.c:1518 #9 0x00007f48657f7a04 in start_thread () from /lib/libpthread.so.0 #10 0x00007f48655617bd in clone () from /lib/libc.so.6 #11 0x0000000000000000 in ?? () (gdb) select 2 (gdb) info locals argv = 0x0 tmp = <value optimized out> progenv = 0x0 i = 1 ret = 1 sb = {st_dev = 64512, st_ino = 140307, st_nlink = 1, st_mode = 33261, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 2293664, st_blksize = 4096, st_blocks = 4480, st_atim = {tv_sec = 1258937087, tv_nsec = 967226499}, st_mtim = { tv_sec = 1257180462, tv_nsec = 0}, st_ctim = {tv_sec = 1258886336, tv_nsec = 104908677}, __unused = {0, 0, 0}} tapfds = 0x0 ntapfds = 1 qemuCmdFlags = 9436542 keepfd = {fds_bits = {262144, 0 <repeats 15 times>}} emulator = <value optimized out> child = 18145 pos = <value optimized out> ebuf = "\220v\036\001\000\000\000\000\060|WeH\177\000\000(\000\000\000\060\000\000\000\000\354\377[H\177\000\000@\353\377[H\177\000\000`\351\377[H\177\000\000\377\377\377\377H\177\000\000\233\017\037\001\000\000\000\000\326\063G\000\000\000\000\000@\247~eH\177\000\000\200\307OeH\177\000\000\240\306OeH\177\000\000JST\000\071\000\000\000\300\352\377[H\177\000\000\342\000\000\000\000\000\000\000\342\000\000\000\000\000\000\000\273\340G\000\000\000\000\000\300\352\377[H\177\000\000K\000\000\000\000\000\000\000`\351\377[H\177\000\000@\354\377[H\177\000\000P\352\377[H\177\000\000\001\000\000\000\000\000\000\000\320\352\377[H\177\000\000$\000\000\000\000\000\000\000py\255eH\177\000\000@\354\377[H\177\000\000\060|WeH\177\000\000\001\200\255\373\000\000\000\000\260\351\377[H\177\000\000\220\354\377[H\177\000\000\240\352\377["... pidfile = 0x0 logfile = 15 hookData = {conn = 0x1219da0, vm = 0x12114f0, driver = 0x11f0110} __FUNCTION__ = "qemudStartVMDaemon" __func__ = "qemudStartVMDaemon"
If you are able to reproduce this crash reliably, can you edit the /etc/libvirt/libvirtd.conf file and add log_filters="1:qemu" log_outputs="1:file:/var/log/libvirtd.log" and then restart libvirtd, and try to make it crash again. Then send us the log file Regards, Daniel -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|
On Wed, Nov 25, 2009 at 11:23:07AM +0000, Daniel P. Berrange wrote:
On Mon, Nov 23, 2009 at 10:08:17PM +0000, Terje Marthinussen wrote:
[ 987.286791] libvirtd[3193]: segfault at 10 ip 00007f921b4546b4 sp 00007f9216e165e0 error 4 in libpthread-2.10.1.so[7f921b44a000+17000]
Ok, so this is the libvirtd daemon crash
From GDB
06:45:32.434: error : qemuMonitorCommandWithHandler:290 : cannot send monitor command 'info cpus': Connection reset by peer
Interestingly this suggests that QEMU itself had quit/crashed during startup. You can check /var/log/libvirt/qemu//$GUESTNAME.log to find out what problem QEMU itself had.
For whatever reason, this seems to then trigger the libvirtd crash
06:45:32.434: error : qemuMonitorTextGetCPUInfo:436 : internal error cannot run monitor command to fetch CPU thread info
Program received signal SIGSEGV, Segmentation fault. [Switching to Thread 0x7f485bfff910 (LWP 18120)] 0x00007f48657fb6b4 in pthread_mutex_unlock () from /lib/libpthread.so.0 (gdb) bt #0 0x00007f48657fb6b4 in pthread_mutex_unlock () from /lib/libpthread.so.0 #1 0x0000000000431101 in qemuDomainObjExitMonitorWithDriver (driver=0x11f0110, obj=0x12114f0) at qemu/qemu_driver.c:318 #2 0x000000000043f436 in qemudStartVMDaemon (conn=<value optimized out>, driver=0x11f0110, vm=0x12114f0, migrateFrom=<value optimized out>, stdin_fd=<value optimized out>) at qemu/qemu_driver.c:2320 #3 0x00000000004407c4 in qemudDomainStart (dom=0x11f0330) at qemu/qemu_driver.c:4370 #4 0x00007f4865a621e7 in virDomainCreate (domain=0x11f0330) at libvirt.c:4509 #5 0x0000000000420d68 in remoteDispatchDomainCreate (server=<value optimized out>, client=<value optimized out>, conn=0x1219da0, hdr=<value optimized out>, rerr=0x7f485bffedf0, args=<value optimized out>, ret=0x7f485bffeed0) at remote.c:853 #6 0x00000000004228e1 in remoteDispatchClientCall (server=<value optimized out>, client=0x7f485c000d30, msg=0x7f485c080f00) at dispatch.c:506 #7 0x0000000000422c93 in remoteDispatchClientRequest (server=0x11e2790, client=0x7f485c000d30, msg=0x7f485c080f00) at dispatch.c:388 #8 0x000000000041625c in qemudWorker (data=<value optimized out>) at libvirtd.c:1518 #9 0x00007f48657f7a04 in start_thread () from /lib/libpthread.so.0 #10 0x00007f48655617bd in clone () from /lib/libc.so.6 #11 0x0000000000000000 in ?? () (gdb) select 2 (gdb) info locals argv = 0x0 tmp = <value optimized out> progenv = 0x0 i = 1 ret = 1 sb = {st_dev = 64512, st_ino = 140307, st_nlink = 1, st_mode = 33261, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 2293664, st_blksize = 4096, st_blocks = 4480, st_atim = {tv_sec = 1258937087, tv_nsec = 967226499}, st_mtim = { tv_sec = 1257180462, tv_nsec = 0}, st_ctim = {tv_sec = 1258886336, tv_nsec = 104908677}, __unused = {0, 0, 0}} tapfds = 0x0 ntapfds = 1 qemuCmdFlags = 9436542 keepfd = {fds_bits = {262144, 0 <repeats 15 times>}} emulator = <value optimized out> child = 18145 pos = <value optimized out> ebuf = "\220v\036\001\000\000\000\000\060|WeH\177\000\000(\000\000\000\060\000\000\000\000\354\377[H\177\000\000@\353\377[H\177\000\000`\351\377[H\177\000\000\377\377\377\377H\177\000\000\233\017\037\001\000\000\000\000\326\063G\000\000\000\000\000@\247~eH\177\000\000\200\307OeH\177\000\000\240\306OeH\177\000\000JST\000\071\000\000\000\300\352\377[H\177\000\000\342\000\000\000\000\000\000\000\342\000\000\000\000\000\000\000\273\340G\000\000\000\000\000\300\352\377[H\177\000\000K\000\000\000\000\000\000\000`\351\377[H\177\000\000@\354\377[H\177\000\000P\352\377[H\177\000\000\001\000\000\000\000\000\000\000\320\352\377[H\177\000\000$\000\000\000\000\000\000\000py\255eH\177\000\000@\354\377[H\177\000\000\060|WeH\177\000\000\001\200\255\373\000\000\000\000\260\351\377[H\177\000\000\220\354\377[H\177\000\000\240\352\377["... pidfile = 0x0 logfile = 15 hookData = {conn = 0x1219da0, vm = 0x12114f0, driver = 0x11f0110} __FUNCTION__ = "qemudStartVMDaemon" __func__ = "qemudStartVMDaemon"
If you are able to reproduce this crash reliably, can you edit the /etc/libvirt/libvirtd.conf file and add
log_filters="1:qemu" log_outputs="1:file:/var/log/libvirtd.log"
and then restart libvirtd, and try to make it crash again. Then send us the log file
Don't bother doing this now - I've figured out the cause of the problem and have a fix pending.. Daniel -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|
participants (2)
-
Daniel P. Berrange -
Terje Marthinussen