Bug 523158

Created attachment 360905 [details]
/var/log/messages of the host

Created attachment 360906 [details]
debug log for virsh save

Created attachment 360912 [details]
debug log for virsh restore


------- Comment on attachment From anoop.vijayan.com 2009-09-14 05:34 EDT-------


Once the restore command is run, connection to the hypervisor gets lost..

[root@mx3650b ~]# virsh list --all
^C <===== hangs here, need to kill

Attaching the debug log for 'virsh restore'

[root@mx3650b ~]# ps -eaf|grep qemu
root     10423 10031 99 12:42 pts/0    02:13:43 /usr/bin/qemu-kvm -S -M pc-0.11 -m 2000 -smp 4 -name rhel5_4_guest -uuid ed1f35f5-207c-5a31-6818-28c06782c1d5 -monitor unix:/var/run/libvirt/qemu/rhel5_4_guest.monitor,server,nowait -boot c -drive file=/var/lib/libvirt/images/rhel5_4_guest.img,if=ide,index=0,boot=on,format=raw -drive file=,if=ide,media=cdrom,index=2 -net nic,macaddr=52:54:00:49:23:9d,vlan=0,name=nic.0 -net tap,fd=19,vlan=0,name=tap.0 -serial pty -parallel none -usb -vnc 127.0.0.1:0 -k en-us -vga cirrus -soundhw es1370
qemu     15445     1 99 14:51 ?        00:07:44 /usr/bin/qemu-kvm -S -M pc-0.11 -m 2000 -smp 4 -name rhel5_4_guest -uuid ed1f35f5-207c-5a31-6818-28c06782c1d5 -monitor unix:/var/run/libvirt/qemu/rhel5_4_guest.monitor,server,nowait -boot c -drive file=/var/lib/libvirt/images/rhel5_4_guest.img,if=ide,index=0,boot=on,format=raw -drive file=,if=ide,media=cdrom,index=2 -net nic,macaddr=52:54:00:49:23:9d,vlan=0,name=nic.0 -net tap,fd=21,vlan=0,name=tap.0 -serial pty -parallel none -usb -vnc 127.0.0.1:1 -k en-us -vga cirrus -soundhw es1370 -incoming exec:cat

[root@mx3650b ~]# ps -eaf|grep libvirtd
root     10815     1  1 13:32 ?        00:01:45 libvirtd --daemon

[root@mx3650b ~]# /etc/init.d/libvirtd status
libvirtd (pid  10815) is running...

Okay, it looks like we might have both a qemu and a libvirtd segfault here. Fun!

What versions of libvirt and qemu is this?

Can you reproduce with the latest versions?

We need to try and get stack traces of both these segfaults if they are still happenining before we can figure out what the problem is

Created attachment 361623 [details]
strace of virsh restore


------- Comment on attachment From santwana.samantray.com 2009-09-18 06:21 EDT-------


Hello Redhat,

I have created an attachment for the strace of virsh restore <guest> .
This is reproducible with the latest versions also, the guest fails to restore from a saved file, and it returns a libvirtd segfault.

Versions installed are:
libvirt-0.7.1-1.fc12.x86_64
qemu-0.10.92-4.fc12.x86_64

Thanks,
Santwana

I'm afraid it's a stack trace of the segfaulting process we need, not an strace

https://fedoraproject.org/wiki/StackTraces

If you're having difficulty obtaining a stack trace, feel free to ask for more help

Created attachment 362290 [details]
stack trace


------- Comment on attachment From santwana.samantray.com 2009-09-23 08:14 EDT-------


Hello Redhat,

I have created an attachment for the stack trace(bt and bt full) of the segfaulting libvirtd process.

Below are the versions installed.
libvirt-client-0.7.1-4.fc12.x86_64
libvirt-0.7.1-4.fc12.x86_64
libvirt-python-0.7.1-4.fc12.x86_64
libvirt-devel-0.7.1-4.fc12.x86_64
libvirt-debuginfo-0.7.1-4.fc12.x86_64

Thanks,
Santwana

santwana: I'm not sure this is a backtrace of a segfault; I think it just may be the debugger stopped when it spawned the qemu process. If you continue on, can you get a stack trace of the actual SEGV ? Thanks

------- Comment From anoop.vijayan.com 2009-10-07 06:50 EDT-------
This is where the segfault occurs.

Program terminated with signal 11, Segmentation fault
#0  0x0000003e6cca7d32 in execvpe () from /lib64/libc.so.6
(gdb) disassemble execvpe
Dump of assembler code for function execvpe:
0x0000003e6cca7d10 <execvpe+0>: push   %rbp
0x0000003e6cca7d11 <execvpe+1>: mov    %rsp,%rbp
0x0000003e6cca7d14 <execvpe+4>: mov    %rbx,-0x28(%rbp)
0x0000003e6cca7d18 <execvpe+8>: mov    %r12,-0x20(%rbp)
0x0000003e6cca7d1c <execvpe+12>:        mov    %rsi,%rbx
0x0000003e6cca7d1f <execvpe+15>:        mov    %r14,-0x10(%rbp)
0x0000003e6cca7d23 <execvpe+19>:        mov    %r13,-0x18(%rbp)
0x0000003e6cca7d27 <execvpe+23>:        mov    %rdi,%r14
0x0000003e6cca7d2a <execvpe+26>:        mov    %r15,-0x8(%rbp)
0x0000003e6cca7d2e <execvpe+30>:        add    $0xffffffffffffff80,%rsp
0x0000003e6cca7d32 <execvpe+34>:        cmpb   $0x0,(%rdi)   <==============
0x0000003e6cca7d35 <execvpe+37>:        mov    %rdx,%r12
0x0000003e6cca7d38 <execvpe+40>:        je     0x3e6cca7d88 <execvpe+120>
0x0000003e6cca7d3a <execvpe+42>:        mov    $0x2f,%esi
0x0000003e6cca7d3f <execvpe+47>:        callq  0x3e6cc7f6f0 <strchr>
0x0000003e6cca7d44 <execvpe+52>:        test   %rax,%rax
0x0000003e6cca7d47 <execvpe+55>:        je     0x3e6cca7e58 <execvpe+328>

(gdb) bt
#0  0x0000003e6cca7d32 in execvpe () from /lib64/libc.so.6
#1  0x0000003e70026286 in __virExec (conn=0x0, argv=<value optimized out>, envp=<value optimized out>, keepfd=<value optimized out>,
retpid=<value optimized out>, infd=16, outfd=<value optimized out>, errfd=<value optimized out>, flags=<value optimized out>,
hook=<value optimized out>, data=<value optimized out>, pidfile=<value optimized out>) at util.c:563
#2  0x0000003e70026c33 in virExecWithHook (conn=0x7f149000c750, argv=0x7f14a5fada30, envp=0x0, keepfd=0x0, retpid=0x7f14a5fada58, infd=16,
outfd=<value optimized out>, errfd=<value optimized out>, flags=<value optimized out>, hook=<value optimized out>,
data=<value optimized out>, pidfile=<value optimized out>) at util.c:612
#3  0x0000003e70026def in virExec (conn=<value optimized out>, argv=<value optimized out>, envp=<value optimized out>,
keepfd=<value optimized out>, retpid=<value optimized out>, infd=<value optimized out>, outfd=<value optimized out>,
errfd=<value optimized out>, flags=<value optimized out>) at util.c:632
#4  0x0000000000435680 in qemudDomainRestore (conn=0x7f149000c750, path=<value optimized out>) at qemu_driver.c:4541
#5  0x0000003e700389bf in virDomainRestore (conn=0x7f149000c750, from=0x7f1494003b70 "/home/newsave") at libvirt.c:2234
#6  0x000000000041c00f in remoteDispatchDomainRestore (server=<value optimized out>, client=<value optimized out>, conn=0x7f149000c750,
rerr=0x7f14a5faebd0, args=<value optimized out>, ret=<value optimized out>) at remote.c:1635
#7  0x000000000041f8f6 in remoteDispatchClientCall (server=<value optimized out>, client=0x21b11e0, msg=0x227c030) at dispatch.c:459
#8  0x000000000041fbb4 in remoteDispatchClientRequest (server=<value optimized out>, client=0x21b11e0, msg=0x227c030) at dispatch.c:359
#9  0x000000000041396c in qemudWorker (data=0x2219120) at qemud.c:1464
#10 0x0000003e6d40696a in start_thread () from /lib64/libpthread.so.0
#11 0x0000003e6cce12cd in clone () from /lib64/libc.so.6
#12 0x0000000000000000 in ?? ()

(gdb) info registers
rax            0x3e6cf7cf60     268116152160
rbx            0x7f14a5fada30   139726660753968
rcx            0xfffffffffffffed0       -304
rdx            0x2179f00        35102464
rsi            0x7f14a5fada30   139726660753968
rdi            0x0      0                                       <=====
rbp            0x7f14a5fad6d0   0x7f14a5fad6d0
rsp            0x7f14a5fad650   0x7f14a5fad650
r8             0x0      0
r9             0x40     64
r10            0x8      8
r11            0x0      0
r12            0x400    1024
r13            0x13     19
r14            0x0      0
r15            0x10     16
rip            0x3e6cca7d32     0x3e6cca7d32 <execvpe+34>
eflags         0x10207  [ CF PF IF RF ]
cs             0x33     51
ss             0x2b     43
ds             0x0      0
es             0x0      0
fs             0x0      0
gs             0x0      0
fctrl          0x37f    895
fstat          0x0      0
ftag           0xffff   65535
fiseg          0x0      0
fioff          0x0      0
foseg          0x0      0
fooff          0x0      0
fop            0x0      0
mxcsr          0x1f80   [ IM DM ZM OM UM PM ]

[root@mx3650b ~]# rpm -q glibc
glibc-2.10.90-22.x86_64

anoop: thanks for the backtrace

danpb, DV, clalance: maybe one of you guys could look at this?

Actually, it's quite odd.  From the disassembly, it looks like it was trying to dereference %rdi.  In the AMD64 calling convention, %rdi holds the first passed parameter, which in this case would be argv[0].  So that suggests that argv[0] is NULL, and then the dereference of that causes the crash.

One way I could imagine this happening is because the save file is actually corrupt.  That is, the original issue mentioned that the save file is only 1.5KB in size, meaning that the save didn't work properly.  So that means we have two bugs here:

1)  Why didn't the save complete properly.
2)  Why a restore from this corrupted save file doesn't just fail, instead of crashing libvirtd.

SANTWANA: can you attach one of those 1.5KB save files to this BZ?  I'm curious what is in them that might be causing this to occur.

Thanks,
Chris Lalancette

I think collecting  a trace of libvirtd  using valgrind could prove much more useful than this stack trace. The actual corruption may well have occurred earlier, and valgrind might do a better job of show where.

Created attachment 364244 [details]
Save file of the guest


------- Comment on attachment From santwana.samantray.com 2009-10-09 09:17 EDT-------


Hello Chris,

I have created an attachment for the guest's save file. Trying to restore from this file, results in segfault of libvirtd.

Thanks,
Santwana

*** Bug 528558 has been marked as a duplicate of this bug. ***

Dan has posted two patches fixing issues with restore:

  http://www.redhat.com/archives/libvir-list/2009-October/msg00337.html
  http://www.redhat.com/archives/libvir-list/2009-October/msg00338.html

The first one should fix this issue

tag request: https://fedorahosted.org/rel-eng/ticket/2528

------- Comment From santwana.samantray.com 2009-10-27 01:51 EDT-------
Hello,

I verified this issue in the latest F12 rawhide (k.v- 2.6.31.5-96.fc12.x86_64), the issue is still existing. While trying to save the guest using " virsh save rhel5.4 /home/guest", it hangs.

The guest is not getting saved to a file. libvirt version installed is "libvirt-0.7.1-13.fc12.x86_64".

Santwana

Santwana - please file a new bug; a 'virsh save' hang is a different bug from a libvirtd segfault during 'virsh restore'

------- Comment From santwana.samantray.com 2009-11-05 06:14 EDT-------
Hi,

I have opened a new bug "Bug 57446 - RH532654- virsh save hangs in Fedora12 rawhide", for "virsh save " hang issue.

Thanks,
Santwana

------- Comment From santwana.samantray.com 2009-11-06 06:54 EDT-------
Hello Anoop,

After applying the patch in Bug 57446 - RH532654- virsh save hangs in Fedora12 rawhide, now virsh restore also works fine. We can close this issue now.

Thanks,
Santwana