[Qemu-devel] Crashing in tcp_close

[Qemu-devel] Crashing in tcp_close

[Brian Candler]

I have some reproducible-ish segfaults in qemu 2.7.0 (built from source) 
running under ubuntu 16.04, on a quad-core i7 Mac Mini Server.

I can reproduce these problems on a different Mac Mini, and I also 
replaced the RAM on mine, so I'm sure it's not hardware related.

It's somewhat painful to reproduce (taking about 30 minutes each 
attempt, and using a lot of network bandwidth).

This is using packer (packer.io) to create a VM and then using ansible 
to do a whole load of package installation and provisioning inside that 
VM.  packer starts qemu with a user-mode network interface.

If I part-build the VM, I can continue the build by restarting it under 
gdb and qemu directly at the command line, and get a backtrace. Here's 
the first one:

Thread 1 "qemu-system-x86" received signal SIGSEGV, Segmentation fault.
0x00007ffff6a1bb5b in _int_free (av=0x7ffff6d5fb20 <main_arena>, 
p=<optimised out>, have_lock=0) at malloc.c:4006
4006    malloc.c: No such file or directory.
(gdb) bt
#0  0x00007ffff6a1bb5b in _int_free (av=0x7ffff6d5fb20 <main_arena>, 
p=<optimised out>, have_lock=0)
     at malloc.c:4006
#1  0x00007ffff6a1fabc in __GI___libc_free (mem=<optimised out>) at 
malloc.c:2969
#2  0x00005555559a6c0f in tcp_close (tp=tp@entry=0x555556621ed0) at 
slirp/tcp_subr.c:334
#3  0x00005555559a6c8f in tcp_drop (tp=tp@entry=0x555556621ed0, 
err=<optimised out>) at slirp/tcp_subr.c:298
#4  0x00005555559a816b in tcp_timers (timer=<optimised out>, 
tp=0x555556621ed0) at slirp/tcp_timer.c:179
#5  tcp_slowtimo (slirp=slirp@entry=0x55555658ecf0) at slirp/tcp_timer.c:89
#6  0x00005555559a0be8 in slirp_pollfds_poll (pollfds=0x555556531f20, 
select_error=select_error@entry=0)
     at slirp/slirp.c:576
#7  0x00005555559d4b0c in main_loop_wait (nonblocking=<optimised out>) 
at main-loop.c:508
#8  0x000055555573fea1 in main_loop () at vl.c:1908
#9  main (argc=<optimised out>, argv=<optimised out>, envp=<optimised 
out>) at vl.c:4604
(gdb)

So:

* Is this of interest?

* If so, what additional gdb output would you like me to provide?

* If developers want to reproduce this, let me know and I can probably 
send the VM qcow2 file and/or packer source privately off-list [I need 
to check permission for that]

Thanks,

Brian Candler.

Re: [Qemu-devel] Crashing in tcp_close

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 2718 bytes --]

On Thu, Oct 20, 2016 at 10:53:50PM +0100, Brian Candler wrote:

CCing slirp maintainers to get attention on this bug

> I have some reproducible-ish segfaults in qemu 2.7.0 (built from source)
> running under ubuntu 16.04, on a quad-core i7 Mac Mini Server.
> 
> I can reproduce these problems on a different Mac Mini, and I also replaced
> the RAM on mine, so I'm sure it's not hardware related.
> 
> It's somewhat painful to reproduce (taking about 30 minutes each attempt,
> and using a lot of network bandwidth).
> 
> This is using packer (packer.io) to create a VM and then using ansible to do
> a whole load of package installation and provisioning inside that VM.
> packer starts qemu with a user-mode network interface.
> 
> If I part-build the VM, I can continue the build by restarting it under gdb
> and qemu directly at the command line, and get a backtrace. Here's the first
> one:
> 
> Thread 1 "qemu-system-x86" received signal SIGSEGV, Segmentation fault.
> 0x00007ffff6a1bb5b in _int_free (av=0x7ffff6d5fb20 <main_arena>,
> p=<optimised out>, have_lock=0) at malloc.c:4006
> 4006    malloc.c: No such file or directory.
> (gdb) bt
> #0  0x00007ffff6a1bb5b in _int_free (av=0x7ffff6d5fb20 <main_arena>,
> p=<optimised out>, have_lock=0)
>     at malloc.c:4006
> #1  0x00007ffff6a1fabc in __GI___libc_free (mem=<optimised out>) at
> malloc.c:2969
> #2  0x00005555559a6c0f in tcp_close (tp=tp@entry=0x555556621ed0) at
> slirp/tcp_subr.c:334
> #3  0x00005555559a6c8f in tcp_drop (tp=tp@entry=0x555556621ed0,
> err=<optimised out>) at slirp/tcp_subr.c:298
> #4  0x00005555559a816b in tcp_timers (timer=<optimised out>,
> tp=0x555556621ed0) at slirp/tcp_timer.c:179
> #5  tcp_slowtimo (slirp=slirp@entry=0x55555658ecf0) at slirp/tcp_timer.c:89
> #6  0x00005555559a0be8 in slirp_pollfds_poll (pollfds=0x555556531f20,
> select_error=select_error@entry=0)
>     at slirp/slirp.c:576
> #7  0x00005555559d4b0c in main_loop_wait (nonblocking=<optimised out>) at
> main-loop.c:508
> #8  0x000055555573fea1 in main_loop () at vl.c:1908
> #9  main (argc=<optimised out>, argv=<optimised out>, envp=<optimised out>)
> at vl.c:4604
> (gdb)
> 
> So:
> 
> * Is this of interest?

Yes.  Thank you for reporting it.

> * If so, what additional gdb output would you like me to provide?

I wonder if this connection has already been closed/freed before and the
timer fires shortly afterward.  That's just a guess based on the
backtrace.

> * If developers want to reproduce this, let me know and I can probably send
> the VM qcow2 file and/or packer source privately off-list [I need to check
> permission for that]
> 
> Thanks,
> 
> Brian Candler.
> 
> 

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

Re: [Qemu-devel] Crashing in tcp_close

[Samuel Thibault]

[-- Attachment #1: Type: text/plain, Size: 2233 bytes --]

Hello,

Stefan Hajnoczi, on Fri 04 Nov 2016 11:14:19 +0000, wrote:
> CCing slirp maintainers to get attention on this bug

Thanks!

> > Thread 1 "qemu-system-x86" received signal SIGSEGV, Segmentation fault.
> > 0x00007ffff6a1bb5b in _int_free (av=0x7ffff6d5fb20 <main_arena>,
> > p=<optimised out>, have_lock=0) at malloc.c:4006
> > 4006    malloc.c: No such file or directory.
> > (gdb) bt
> > #0  0x00007ffff6a1bb5b in _int_free (av=0x7ffff6d5fb20 <main_arena>,
> > p=<optimised out>, have_lock=0)
> >     at malloc.c:4006
> > #1  0x00007ffff6a1fabc in __GI___libc_free (mem=<optimised out>) at
> > malloc.c:2969
> > #2  0x00005555559a6c0f in tcp_close (tp=tp@entry=0x555556621ed0) at
> > slirp/tcp_subr.c:334
> > #3  0x00005555559a6c8f in tcp_drop (tp=tp@entry=0x555556621ed0,
> > err=<optimised out>) at slirp/tcp_subr.c:298
> > #4  0x00005555559a816b in tcp_timers (timer=<optimised out>,
> > tp=0x555556621ed0) at slirp/tcp_timer.c:179
> > #3  0x00005555559a6c8f in tcp_drop (tp=tp@entry=0x555556621ed0,
> > err=<optimised out>) at slirp/tcp_subr.c:298
> > #4  0x00005555559a816b in tcp_timers (timer=<optimised out>,
> > tp=0x555556621ed0) at slirp/tcp_timer.c:179
> > #5  tcp_slowtimo (slirp=slirp@entry=0x55555658ecf0) at slirp/tcp_timer.c:89

> > * If so, what additional gdb output would you like me to provide?
> 
> I wonder if this connection has already been closed/freed before and the
> timer fires shortly afterward.  That's just a guess based on the
> backtrace.

That's very unlikely: soclose removes the socket from the list, so
tcp_slowtimo wouldn't be able to find it. That'd rather be a buffer
overflow. But it's hard to believe it could come from the socket
structure since it doesn't contain any buffer.

Brian, could you run it with

export MALLOC_CHECK_=2

and also this could be useful:

export MALLOC_PERTURB_=1234

Also, to rule out the double-free scenario, and try to catch a buffer
overflow coming from the socket structure itself, I have attached a
patch which adds some debugging.

> > * If developers want to reproduce this, let me know and I can probably send
> > the VM qcow2 file and/or packer source privately off-list [I need to check
> > permission for that]

That could be useful.

Samuel

[-- Attachment #2: patch --]
[-- Type: text/plain, Size: 1375 bytes --]

diff --git a/slirp/socket.c b/slirp/socket.c
index 280050a..e603164 100644
--- a/slirp/socket.c
+++ b/slirp/socket.c
@@ -51,10 +51,12 @@ socreate(Slirp *slirp)
   so = (struct socket *)malloc(sizeof(struct socket));
   if(so) {
     memset(so, 0, sizeof(struct socket));
+    so->canary1 = 0xdeadbeef;
     so->so_state = SS_NOFDREF;
     so->s = -1;
     so->slirp = slirp;
     so->pollfds_idx = -1;
+    so->canary2 = 0xbe3fd3ad;
   }
   return(so);
 }
@@ -67,6 +69,14 @@ sofree(struct socket *so)
 {
   Slirp *slirp = so->slirp;
 
+  if (so->s == -1234)
+    fprintf(stderr,"oops, re-freeing a freed socket!\n");
+  if (so->canary1 != 0xdeadbeef)
+    fprintf(stderr,"oops, canary1 bogus!\n");
+  if (so->canary2 != 0xbe3fd3ad)
+    fprintf(stderr,"oops, canary2 bogus!\n");
+  so->s = -1234;
+
   if (so->so_emu==EMU_RSH && so->extra) {
 	sofree(so->extra);
 	so->extra=NULL;
diff --git a/slirp/socket.h b/slirp/socket.h
index 8feed2a..14fac1c 100644
--- a/slirp/socket.h
+++ b/slirp/socket.h
@@ -17,6 +17,7 @@
 
 struct socket {
   struct socket *so_next,*so_prev;      /* For a linked list of sockets */
+  int canary1;
 
   int s;                           /* The actual socket */
 
@@ -70,6 +71,7 @@ struct socket {
   struct sbuf so_rcv;		/* Receive buffer */
   struct sbuf so_snd;		/* Send buffer */
   void * extra;			/* Extra pointer */
+  int canary2;
 };
 
 

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 06/11/2016 18:04, Samuel Thibault wrote:
> Brian, could you run it with
>
> export MALLOC_CHECK_=2
>
> and also this could be useful:
>
> export MALLOC_PERTURB_=1234
>
> Also, to rule out the double-free scenario, and try to catch a buffer
> overflow coming from the socket structure itself, I have attached a
> patch which adds some debugging.

Thanks. I've added the patch, and re-run the stress test.

(Aside: since last post I've replaced the Mac Mini with Intel NUCi6KYK 
so it's not *exactly* the same environment, although both machines are 
quad-core i7)

Unfortunately it doesn't crash every time. Here are the first two 
crashes I've managed to obtain, and they don't seem to by anything to do 
with tcp_close, but I have pasted them below. I have kept the coredumps 
if there's anything more useful I can extract from them.

The full command line is something like this (taken from a later run):

/usr/local/bin/qemu-system-x86_64 -m 4G -machine type=pc,accel=kvm 
-netdev user,id=user.0,hostfwd=tcp::2305-:22 -device 
virtio-scsi-pci,id=scsi0 -device scsi-hd,bus=scsi0.0,drive=drive0 
-device virtio-net,netdev=user.0 -name vtp-nmm-201611070837.qcow2 -drive 
if=none,file=output-qemu-vtp-nmm/vtp-nmm-201611070837.qcow2,id=drive0,cache=writeback,discard=unmap,format=qcow2 
-boot c -vnc [::]:24

The following crashes occurred when running with a single vcpu. Normally 
I have been running with -smp 8,sockets=1,cores=4,threads=2 as it seems 
to crash less with those settings; however I'm trying it again like that 
in a loop to see if I can get a crash.

Regards,

Brian.

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/local/bin/qemu-system-x86_64 -m 4G -name 
vtp-nmm-201611062024.qcow2 -machi'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f366c4ce428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
54      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
[Current thread is 1 (Thread 0x7f366deeea80 (LWP 9030))]
(gdb) bt
#0  0x00007f366c4ce428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00007f366c4d002a in __GI_abort () at abort.c:89
#2  0x00007f366c4c6bd7 in __assert_fail_base (fmt=<optimised out>,
     assertion=assertion@entry=0x560907875cd5 "mr != NULL",
     file=file@entry=0x560907857884 "/home/nsrc/qemu-2.7.0/exec.c", 
line=line@entry=2967,
     function=function@entry=0x560907857f00 <__PRETTY_FUNCTION__.42881> 
"address_space_unmap")
     at assert.c:92
#3  0x00007f366c4c6c82 in __GI___assert_fail (
     assertion=assertion@entry=0x560907875cd5 "mr != NULL",
     file=file@entry=0x560907857884 "/home/nsrc/qemu-2.7.0/exec.c", 
line=line@entry=2967,
     function=function@entry=0x560907857f00 <__PRETTY_FUNCTION__.42881> 
"address_space_unmap")
     at assert.c:101
#4  0x000056090749dffe in address_space_unmap (as=<optimised out>, 
buffer=<optimised out>,
     len=<optimised out>, is_write=1, access_len=8192) at 
/home/nsrc/qemu-2.7.0/exec.c:2967
#5  0x00005609075af586 in dma_memory_unmap (access_len=<optimised out>, 
dir=<optimised out>,
     len=<optimised out>, buffer=<optimised out>, as=<optimised out>)
     at /home/nsrc/qemu-2.7.0/include/sysemu/dma.h:144
#6  dma_blk_unmap (dbs=dbs@entry=0x560909ceca90) at 
/home/nsrc/qemu-2.7.0/dma-helpers.c:102
#7  0x00005609075af766 in dma_complete (ret=0, dbs=0x560909ceca90)
     at /home/nsrc/qemu-2.7.0/dma-helpers.c:113
#8  dma_blk_cb (opaque=0x560909ceca90, ret=0) at 
/home/nsrc/qemu-2.7.0/dma-helpers.c:137
#9  0x000056090775d25a in blk_aio_complete (acb=0x56090909aba0)
     at /home/nsrc/qemu-2.7.0/block/block-backend.c:923
#10 0x00005609077ccaea in coroutine_trampoline (i0=<optimised out>, 
i1=<optimised out>)
     at /home/nsrc/qemu-2.7.0/util/coroutine-ucontext.c:78
#11 0x00007f366c4e35d0 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#12 0x00007fffd8d31f20 in ?? ()
#13 0x2d2d2d2d2d2d2d2d in ?? ()
#14 0x00000000000000d0 in ?? ()
#15 0x0000000000000000 in ?? ()
(gdb)


[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/local/bin/qemu-system-x86_64 -boot c -vnc 
[::]:78 -name vtp-nmm-2016110621'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007fc226c98428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
54      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
[Current thread is 1 (Thread 0x7fc2286b8a80 (LWP 10267))]
(gdb) bt
#0  0x00007fc226c98428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00007fc226c9a02a in __GI_abort () at abort.c:89
#2  0x00007fc226c90bd7 in __assert_fail_base (fmt=<optimised out>,
     assertion=assertion@entry=0x561867557cd5 "mr != NULL",
     file=file@entry=0x561867539884 "/home/nsrc/qemu-2.7.0/exec.c", 
line=line@entry=2967,
     function=function@entry=0x561867539f00 <__PRETTY_FUNCTION__.42881> 
"address_space_unmap")
     at assert.c:92
#3  0x00007fc226c90c82 in __GI___assert_fail (
     assertion=assertion@entry=0x561867557cd5 "mr != NULL",
     file=file@entry=0x561867539884 "/home/nsrc/qemu-2.7.0/exec.c", 
line=line@entry=2967,
     function=function@entry=0x561867539f00 <__PRETTY_FUNCTION__.42881> 
"address_space_unmap")
     at assert.c:101
#4  0x000056186717fffe in address_space_unmap (as=<optimised out>, 
buffer=<optimised out>,
     len=<optimised out>, is_write=1, access_len=4096) at 
/home/nsrc/qemu-2.7.0/exec.c:2967
#5  0x0000561867202beb in virtqueue_unmap_sg 
(elem=elem@entry=0x5618694fc610, len=len@entry=32876,
     vq=0x5618695a8500) at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:254
#6  0x0000561867203422 in virtqueue_fill (vq=vq@entry=0x5618695a8500,
     elem=elem@entry=0x5618694fc610, len=32876, idx=idx@entry=0)
     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:282
#7  0x00005618672035db in virtqueue_push (vq=vq@entry=0x5618695a8500,
     elem=elem@entry=0x5618694fc610, len=<optimised out>)
     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:308
#8  0x00005618671f0885 in virtio_scsi_complete_req (req=0x5618694fc610)
     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:70
#9  0x00005618671f09e6 in virtio_scsi_complete_cmd_req (req=0x5618694fc610)
     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:443
#10 virtio_scsi_command_complete (r=<optimised out>, status=0, resid=0)
     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:470
#11 0x0000561867365c98 in scsi_req_complete (req=0x561868a72e40, 
status=<optimised out>)
     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-bus.c:1775
#12 0x0000561867360210 in scsi_dma_complete_noio (r=0x561868a72e40, 
ret=<optimised out>)
     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-disk.c:278
---Type <return> to continue, or q <return> to quit---
#13 0x0000561867291779 in dma_complete (ret=0, dbs=0x561868371050)
     at /home/nsrc/qemu-2.7.0/dma-helpers.c:115
#14 dma_blk_cb (opaque=0x561868371050, ret=0) at 
/home/nsrc/qemu-2.7.0/dma-helpers.c:137
#15 0x000056186743f25a in blk_aio_complete (acb=0x561869661b90)
     at /home/nsrc/qemu-2.7.0/block/block-backend.c:923
#16 0x00005618674aeaea in coroutine_trampoline (i0=<optimised out>, 
i1=<optimised out>)
     at /home/nsrc/qemu-2.7.0/util/coroutine-ucontext.c:78
#17 0x00007fc226cad5d0 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#18 0x00007ffd10673d70 in ?? ()
#19 0x2d2d2d2d2d2d2d2d in ?? ()
#20 0x00000000000000d4 in ?? ()
#21 0x0000000000000000 in ?? ()
(gdb)

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 07/11/2016 08:42, Brian Candler wrote:
> The following crashes occurred when running with a single vcpu. 
> Normally I have been running with -smp 8,sockets=1,cores=4,threads=2 
> as it seems to crash less with those settings; however I'm trying it 
> again like that in a loop to see if I can get a crash. 

On the next try I got another SCSI-related crash (see below).  I changed 
from virtio to virtio-scsi a little while ago so that I could get "trim" 
functionality.  So I'll now try with regular virtio and see if I can 
reproduce anything that way.

Regards,

Brian.

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/local/bin/qemu-system-x86_64 -device 
virtio-scsi-pci,id=scsi0 -device scsi'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f1cbe351428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
54    ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
[Current thread is 1 (Thread 0x7f1cbfd71a80 (LWP 17371))]
(gdb) bt
#0  0x00007f1cbe351428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00007f1cbe35302a in __GI_abort () at abort.c:89
#2  0x00007f1cbe349bd7 in __assert_fail_base (fmt=<optimised out>,
     assertion=assertion@entry=0x55fc650aecd5 "mr != NULL",
     file=file@entry=0x55fc65090884 "/home/nsrc/qemu-2.7.0/exec.c", 
line=line@entry=2967,
     function=function@entry=0x55fc65090f00 <__PRETTY_FUNCTION__.42881> 
"address_space_unmap")
     at assert.c:92
#3  0x00007f1cbe349c82 in __GI___assert_fail (
     assertion=assertion@entry=0x55fc650aecd5 "mr != NULL",
     file=file@entry=0x55fc65090884 "/home/nsrc/qemu-2.7.0/exec.c", 
line=line@entry=2967,
     function=function@entry=0x55fc65090f00 <__PRETTY_FUNCTION__.42881> 
"address_space_unmap")
     at assert.c:101
#4  0x000055fc64cd6ffe in address_space_unmap (as=<optimised out>, 
buffer=<optimised out>,
     len=<optimised out>, is_write=1, access_len=4096) at 
/home/nsrc/qemu-2.7.0/exec.c:2967
#5  0x000055fc64d59beb in virtqueue_unmap_sg 
(elem=elem@entry=0x55fc6662d7a0, len=len@entry=24684,
     vq=0x7f1bb8470110) at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:254
#6  0x000055fc64d5a422 in virtqueue_fill (vq=vq@entry=0x7f1bb8470110,
     elem=elem@entry=0x55fc6662d7a0, len=24684, idx=idx@entry=0)
     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:282
#7  0x000055fc64d5a5db in virtqueue_push (vq=vq@entry=0x7f1bb8470110,
     elem=elem@entry=0x55fc6662d7a0, len=<optimised out>)
     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:308
#8  0x000055fc64d47885 in virtio_scsi_complete_req (req=0x55fc6662d7a0)
     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:70
#9  0x000055fc64d479e6 in virtio_scsi_complete_cmd_req (req=0x55fc6662d7a0)
     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:443
#10 virtio_scsi_command_complete (r=<optimised out>, status=0, resid=0)
     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:470
#11 0x000055fc64ebcc98 in scsi_req_complete (req=0x55fc67044eb0, 
status=<optimised out>)
     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-bus.c:1775
#12 0x000055fc64eb7210 in scsi_dma_complete_noio (r=0x55fc67044eb0, 
ret=<optimised out>)
     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-disk.c:278
---Type <return> to continue, or q <return> to quit---
#13 0x000055fc64de8779 in dma_complete (ret=0, dbs=0x55fc66629e30)
     at /home/nsrc/qemu-2.7.0/dma-helpers.c:115
#14 dma_blk_cb (opaque=0x55fc66629e30, ret=0) at 
/home/nsrc/qemu-2.7.0/dma-helpers.c:137
#15 0x000055fc64f9625a in blk_aio_complete (acb=0x55fc662b70a0)
     at /home/nsrc/qemu-2.7.0/block/block-backend.c:923
#16 0x000055fc65005aea in coroutine_trampoline (i0=<optimised out>, 
i1=<optimised out>)
     at /home/nsrc/qemu-2.7.0/util/coroutine-ucontext.c:78
#17 0x00007f1cbe3665d0 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#18 0x00007fffb0541d10 in ?? ()
#19 0x2d2d2d2d2d2d2d2d in ?? ()
#20 0x00000000000000ec in ?? ()
#21 0x0000000000000000 in ?? ()
(gdb)

Re: [Qemu-devel] Crashing in tcp_close

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 8725 bytes --]

On Mon, Nov 07, 2016 at 08:42:17AM +0000, Brian Candler wrote:
> On 06/11/2016 18:04, Samuel Thibault wrote:
> > Brian, could you run it with
> > 
> > export MALLOC_CHECK_=2
> > 
> > and also this could be useful:
> > 
> > export MALLOC_PERTURB_=1234
> > 
> > Also, to rule out the double-free scenario, and try to catch a buffer
> > overflow coming from the socket structure itself, I have attached a
> > patch which adds some debugging.
> 
> Thanks. I've added the patch, and re-run the stress test.
> 
> (Aside: since last post I've replaced the Mac Mini with Intel NUCi6KYK so
> it's not *exactly* the same environment, although both machines are
> quad-core i7)
> 
> Unfortunately it doesn't crash every time. Here are the first two crashes
> I've managed to obtain, and they don't seem to by anything to do with
> tcp_close, but I have pasted them below. I have kept the coredumps if
> there's anything more useful I can extract from them.
> 
> The full command line is something like this (taken from a later run):
> 
> /usr/local/bin/qemu-system-x86_64 -m 4G -machine type=pc,accel=kvm -netdev
> user,id=user.0,hostfwd=tcp::2305-:22 -device virtio-scsi-pci,id=scsi0
> -device scsi-hd,bus=scsi0.0,drive=drive0 -device virtio-net,netdev=user.0
> -name vtp-nmm-201611070837.qcow2 -drive if=none,file=output-qemu-vtp-nmm/vtp-nmm-201611070837.qcow2,id=drive0,cache=writeback,discard=unmap,format=qcow2
> -boot c -vnc [::]:24
> 
> The following crashes occurred when running with a single vcpu. Normally I
> have been running with -smp 8,sockets=1,cores=4,threads=2 as it seems to
> crash less with those settings; however I'm trying it again like that in a
> loop to see if I can get a crash.

Let's try to isolate the cause of this crash:

Are you able to switch -netdev user to -netdev tap so we can rule out
the slirp user network stack as the source of memory corruption?

Alternatively could you re-run with virtio-blk instead of virtio-scsi to
see if that eliminates crashes?

The core dumps are likely to contain more clues.  If you are comfortable
with gdb and debugging C code you could dump the memory surround where
the junk value (mr) was loaded from.  Perhaps there is a hint about who
zeroed the memory.  In the first core dump you could start with:

 (gdb) up 6  # go to the dma_blk_unmap() stack frame
 (gdb) p *(DMAAIOCB *)0x560909ceca90
 (gdb) p *((DMAAIOCB *)0x560909ceca90).sg

> Regards,
> 
> Brian.
> 
> [Thread debugging using libthread_db enabled]
> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
> Core was generated by `/usr/local/bin/qemu-system-x86_64 -m 4G -name
> vtp-nmm-201611062024.qcow2 -machi'.
> Program terminated with signal SIGABRT, Aborted.
> #0  0x00007f366c4ce428 in __GI_raise (sig=sig@entry=6) at
> ../sysdeps/unix/sysv/linux/raise.c:54
> 54      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
> [Current thread is 1 (Thread 0x7f366deeea80 (LWP 9030))]
> (gdb) bt
> #0  0x00007f366c4ce428 in __GI_raise (sig=sig@entry=6) at
> ../sysdeps/unix/sysv/linux/raise.c:54
> #1  0x00007f366c4d002a in __GI_abort () at abort.c:89
> #2  0x00007f366c4c6bd7 in __assert_fail_base (fmt=<optimised out>,
>     assertion=assertion@entry=0x560907875cd5 "mr != NULL",
>     file=file@entry=0x560907857884 "/home/nsrc/qemu-2.7.0/exec.c",
> line=line@entry=2967,
>     function=function@entry=0x560907857f00 <__PRETTY_FUNCTION__.42881>
> "address_space_unmap")
>     at assert.c:92
> #3  0x00007f366c4c6c82 in __GI___assert_fail (
>     assertion=assertion@entry=0x560907875cd5 "mr != NULL",
>     file=file@entry=0x560907857884 "/home/nsrc/qemu-2.7.0/exec.c",
> line=line@entry=2967,
>     function=function@entry=0x560907857f00 <__PRETTY_FUNCTION__.42881>
> "address_space_unmap")
>     at assert.c:101
> #4  0x000056090749dffe in address_space_unmap (as=<optimised out>,
> buffer=<optimised out>,
>     len=<optimised out>, is_write=1, access_len=8192) at
> /home/nsrc/qemu-2.7.0/exec.c:2967
> #5  0x00005609075af586 in dma_memory_unmap (access_len=<optimised out>,
> dir=<optimised out>,
>     len=<optimised out>, buffer=<optimised out>, as=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/include/sysemu/dma.h:144
> #6  dma_blk_unmap (dbs=dbs@entry=0x560909ceca90) at
> /home/nsrc/qemu-2.7.0/dma-helpers.c:102
> #7  0x00005609075af766 in dma_complete (ret=0, dbs=0x560909ceca90)
>     at /home/nsrc/qemu-2.7.0/dma-helpers.c:113
> #8  dma_blk_cb (opaque=0x560909ceca90, ret=0) at
> /home/nsrc/qemu-2.7.0/dma-helpers.c:137
> #9  0x000056090775d25a in blk_aio_complete (acb=0x56090909aba0)
>     at /home/nsrc/qemu-2.7.0/block/block-backend.c:923
> #10 0x00005609077ccaea in coroutine_trampoline (i0=<optimised out>,
> i1=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/util/coroutine-ucontext.c:78
> #11 0x00007f366c4e35d0 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
> #12 0x00007fffd8d31f20 in ?? ()
> #13 0x2d2d2d2d2d2d2d2d in ?? ()
> #14 0x00000000000000d0 in ?? ()
> #15 0x0000000000000000 in ?? ()
> (gdb)
> 
> 
> [Thread debugging using libthread_db enabled]
> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
> Core was generated by `/usr/local/bin/qemu-system-x86_64 -boot c -vnc
> [::]:78 -name vtp-nmm-2016110621'.
> Program terminated with signal SIGABRT, Aborted.
> #0  0x00007fc226c98428 in __GI_raise (sig=sig@entry=6) at
> ../sysdeps/unix/sysv/linux/raise.c:54
> 54      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
> [Current thread is 1 (Thread 0x7fc2286b8a80 (LWP 10267))]
> (gdb) bt
> #0  0x00007fc226c98428 in __GI_raise (sig=sig@entry=6) at
> ../sysdeps/unix/sysv/linux/raise.c:54
> #1  0x00007fc226c9a02a in __GI_abort () at abort.c:89
> #2  0x00007fc226c90bd7 in __assert_fail_base (fmt=<optimised out>,
>     assertion=assertion@entry=0x561867557cd5 "mr != NULL",
>     file=file@entry=0x561867539884 "/home/nsrc/qemu-2.7.0/exec.c",
> line=line@entry=2967,
>     function=function@entry=0x561867539f00 <__PRETTY_FUNCTION__.42881>
> "address_space_unmap")
>     at assert.c:92
> #3  0x00007fc226c90c82 in __GI___assert_fail (
>     assertion=assertion@entry=0x561867557cd5 "mr != NULL",
>     file=file@entry=0x561867539884 "/home/nsrc/qemu-2.7.0/exec.c",
> line=line@entry=2967,
>     function=function@entry=0x561867539f00 <__PRETTY_FUNCTION__.42881>
> "address_space_unmap")
>     at assert.c:101
> #4  0x000056186717fffe in address_space_unmap (as=<optimised out>,
> buffer=<optimised out>,
>     len=<optimised out>, is_write=1, access_len=4096) at
> /home/nsrc/qemu-2.7.0/exec.c:2967
> #5  0x0000561867202beb in virtqueue_unmap_sg
> (elem=elem@entry=0x5618694fc610, len=len@entry=32876,
>     vq=0x5618695a8500) at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:254
> #6  0x0000561867203422 in virtqueue_fill (vq=vq@entry=0x5618695a8500,
>     elem=elem@entry=0x5618694fc610, len=32876, idx=idx@entry=0)
>     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:282
> #7  0x00005618672035db in virtqueue_push (vq=vq@entry=0x5618695a8500,
>     elem=elem@entry=0x5618694fc610, len=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:308
> #8  0x00005618671f0885 in virtio_scsi_complete_req (req=0x5618694fc610)
>     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:70
> #9  0x00005618671f09e6 in virtio_scsi_complete_cmd_req (req=0x5618694fc610)
>     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:443
> #10 virtio_scsi_command_complete (r=<optimised out>, status=0, resid=0)
>     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:470
> #11 0x0000561867365c98 in scsi_req_complete (req=0x561868a72e40,
> status=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-bus.c:1775
> #12 0x0000561867360210 in scsi_dma_complete_noio (r=0x561868a72e40,
> ret=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-disk.c:278
> ---Type <return> to continue, or q <return> to quit---
> #13 0x0000561867291779 in dma_complete (ret=0, dbs=0x561868371050)
>     at /home/nsrc/qemu-2.7.0/dma-helpers.c:115
> #14 dma_blk_cb (opaque=0x561868371050, ret=0) at
> /home/nsrc/qemu-2.7.0/dma-helpers.c:137
> #15 0x000056186743f25a in blk_aio_complete (acb=0x561869661b90)
>     at /home/nsrc/qemu-2.7.0/block/block-backend.c:923
> #16 0x00005618674aeaea in coroutine_trampoline (i0=<optimised out>,
> i1=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/util/coroutine-ucontext.c:78
> #17 0x00007fc226cad5d0 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
> #18 0x00007ffd10673d70 in ?? ()
> #19 0x2d2d2d2d2d2d2d2d in ?? ()
> #20 0x00000000000000d4 in ?? ()
> #21 0x0000000000000000 in ?? ()
> (gdb)
> 
> 

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 07/11/2016 10:42, Stefan Hajnoczi wrote:
> Let's try to isolate the cause of this crash:
>
> Are you able to switch -netdev user to -netdev tap so we can rule out
> the slirp user network stack as the source of memory corruption?
Let me try to set that up. Using packer.io, I will have to start a VM by 
hand, and then use the 'null' builder to ssh to the existing VM (whereas 
normally packer fires up the qemu process by itself)

> Alternatively could you re-run with virtio-blk instead of virtio-scsi to
> see if that eliminates crashes?
This is what I got after changing to virtio:

Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/local/bin/qemu-system-x86_64 -netdev 
user,id=user.0,hostfwd=tcp::2521-:22'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007fa76d645428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
54    ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
[Current thread is 1 (Thread 0x7fa76f065a80 (LWP 18155))]
(gdb) bt
#0  0x00007fa76d645428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00007fa76d64702a in __GI_abort () at abort.c:89
#2  0x00007fa76d63dbd7 in __assert_fail_base (fmt=<optimised out>,
     assertion=assertion@entry=0x5629cea98cd5 "mr != NULL",
     file=file@entry=0x5629cea7a884 "/home/nsrc/qemu-2.7.0/exec.c", 
line=line@entry=2967,
     function=function@entry=0x5629cea7af00 <__PRETTY_FUNCTION__.42881> 
"address_space_unmap")
     at assert.c:92
#3  0x00007fa76d63dc82 in __GI___assert_fail (
     assertion=assertion@entry=0x5629cea98cd5 "mr != NULL",
     file=file@entry=0x5629cea7a884 "/home/nsrc/qemu-2.7.0/exec.c", 
line=line@entry=2967,
     function=function@entry=0x5629cea7af00 <__PRETTY_FUNCTION__.42881> 
"address_space_unmap")
     at assert.c:101
#4  0x00005629ce6c0ffe in address_space_unmap (as=<optimised out>, 
buffer=<optimised out>,
     len=<optimised out>, is_write=1, access_len=4096) at 
/home/nsrc/qemu-2.7.0/exec.c:2967
#5  0x00005629ce743beb in virtqueue_unmap_sg 
(elem=elem@entry=0x5629d29d5290, len=len@entry=61441,
     vq=0x5629d13186b0) at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:254
#6  0x00005629ce744422 in virtqueue_fill (vq=vq@entry=0x5629d13186b0,
     elem=elem@entry=0x5629d29d5290, len=61441, idx=idx@entry=0)
     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:282
#7  0x00005629ce7445db in virtqueue_push (vq=0x5629d13186b0, 
elem=elem@entry=0x5629d29d5290,
     len=<optimised out>) at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:308
#8  0x00005629ce71894d in virtio_blk_req_complete 
(req=req@entry=0x5629d29d5290,
     status=status@entry=0 '\000') at 
/home/nsrc/qemu-2.7.0/hw/block/virtio-blk.c:58
#9  0x00005629ce718b59 in virtio_blk_rw_complete (opaque=<optimised 
out>, ret=0)
     at /home/nsrc/qemu-2.7.0/hw/block/virtio-blk.c:121
#10 0x00005629ce98025a in blk_aio_complete (acb=0x5629d298f370)
     at /home/nsrc/qemu-2.7.0/block/block-backend.c:923
#11 0x00005629ce9efaea in coroutine_trampoline (i0=<optimised out>, 
i1=<optimised out>)
     at /home/nsrc/qemu-2.7.0/util/coroutine-ucontext.c:78
#12 0x00007fa76d65a5d0 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#13 0x00007ffee3d75a20 in ?? ()
#14 0x2d2d2d2d2d2d2d2d in ?? ()
---Type <return> to continue, or q <return> to quit---
#15 0x00000000000000f0 in ?? ()
#16 0x0000000000000000 in ?? ()

Aside: I see "virtqueue_unmap_sg" in the backtrace. Is this correct even 
for a non-SCSI virtio?

The command line was something like this (captured by running packer 
another time, so the ports and filenames are not exactly the same)

/usr/local/bin/qemu-system-x86_64 -m 4G -vnc [::]:59 -machine 
type=pc,accel=kvm -netdev user,id=user.0,hostfwd=tcp::2879-:22 -boot c 
-smp 8,sockets=1,cores=4,threads=2 -name vtp-nmm-201611071057.qcow2 
-device virtio-net,netdev=user.0 -drive 
file=output-qemu-vtp-nmm/vtp-nmm-201611071057.qcow2,if=virtio,cache=writeback,discard=ignore,format=qcow2


> The core dumps are likely to contain more clues.  If you are comfortable
> with gdb and debugging C code you could dump the memory surround where
> the junk value (mr) was loaded from.  Perhaps there is a hint about who
> zeroed the memory.  In the first core dump you could start with:
>
>   (gdb) up 6  # go to the dma_blk_unmap() stack frame
>   (gdb) p *(DMAAIOCB *)0x560909ceca90
>   (gdb) p *((DMAAIOCB *)0x560909ceca90).sg

(gdb) up 6
#6  dma_blk_unmap (dbs=dbs@entry=0x560909ceca90) at 
/home/nsrc/qemu-2.7.0/dma-helpers.c:102
102            dma_memory_unmap(dbs->sg->as, dbs->iov.iov[i].iov_base,
(gdb) p *(DMAAIOCB *)0x560909ceca90
$1 = {common = {aiocb_info = 0x560907c15690 <dma_aiocb_info>, bs = 0x0,
     cb = 0x56090767e250 <scsi_dma_complete>, opaque = 0x560909c2b8e0, 
refcnt = 1},
   ctx = 0x5609087d82a0, acb = 0x0, sg = 0x560909af7430, offset = 
4302675968,
   dir = DMA_DIRECTION_FROM_DEVICE, sg_cur_index = 126, sg_cur_byte = 0, 
iov = {
     iov = 0x560909c6e960, niov = 126, nalloc = 126, size = 1048576}, bh 
= 0x0,
   io_func = 0x56090767d110 <scsi_dma_readv>, io_func_opaque = 
0x560909c2b8e0}
(gdb) p *((DMAAIOCB *)0x560909ceca90).sg
$2 = {sg = 0x560909fab1e0, nsg = 126, nalloc = 143, size = 1048576, dev 
= 0x5609087e5630,
   as = 0x560907e20480 <address_space_memory>}
(gdb)

I'm comfortable with C, but don't really know what I'm looking for, nor 
what the data structures represent :-)

(gdb) p dbs->iov.niov
$3 = 126
(gdb) p i
$4 = 125

...so it appears it was in the last iteration of the loop.

(gdb) print dbs->sg->as
$5 = (AddressSpace *) 0x560907e20480 <address_space_memory>
(gdb) print dbs->iov.iov[i].iov_base
$6 = (void *) 0x7f354099e000
(gdb) print dbs->iov.iov[i].iov_len
$7 = 8192
(gdb) print dbs->dir
$8 = DMA_DIRECTION_FROM_DEVICE

Unfortunately, much has been inlined:

(gdb) frame 4
#4  0x000056090749dffe in address_space_unmap (as=<optimised out>, 
buffer=<optimised out>,
     len=<optimised out>, is_write=1, access_len=8192) at 
/home/nsrc/qemu-2.7.0/exec.c:2967
2967            assert(mr != NULL);
(gdb) print mr
$9 = (MemoryRegion *) 0x0
(gdb) print buffer
$10 = <optimised out>
(gdb)

Regards,

Brian.

Re: [Qemu-devel] Crashing in tcp_close

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 7009 bytes --]

On Mon, Nov 07, 2016 at 11:09:10AM +0000, Brian Candler wrote:
> On 07/11/2016 10:42, Stefan Hajnoczi wrote:
> > Let's try to isolate the cause of this crash:
> > 
> > Are you able to switch -netdev user to -netdev tap so we can rule out
> > the slirp user network stack as the source of memory corruption?
> Let me try to set that up. Using packer.io, I will have to start a VM by
> hand, and then use the 'null' builder to ssh to the existing VM (whereas
> normally packer fires up the qemu process by itself)
> 
> > Alternatively could you re-run with virtio-blk instead of virtio-scsi to
> > see if that eliminates crashes?
> This is what I got after changing to virtio:
> 
> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
> Core was generated by `/usr/local/bin/qemu-system-x86_64 -netdev
> user,id=user.0,hostfwd=tcp::2521-:22'.
> Program terminated with signal SIGABRT, Aborted.
> #0  0x00007fa76d645428 in __GI_raise (sig=sig@entry=6) at
> ../sysdeps/unix/sysv/linux/raise.c:54
> 54    ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
> [Current thread is 1 (Thread 0x7fa76f065a80 (LWP 18155))]
> (gdb) bt
> #0  0x00007fa76d645428 in __GI_raise (sig=sig@entry=6) at
> ../sysdeps/unix/sysv/linux/raise.c:54
> #1  0x00007fa76d64702a in __GI_abort () at abort.c:89
> #2  0x00007fa76d63dbd7 in __assert_fail_base (fmt=<optimised out>,
>     assertion=assertion@entry=0x5629cea98cd5 "mr != NULL",
>     file=file@entry=0x5629cea7a884 "/home/nsrc/qemu-2.7.0/exec.c",
> line=line@entry=2967,
>     function=function@entry=0x5629cea7af00 <__PRETTY_FUNCTION__.42881>
> "address_space_unmap")
>     at assert.c:92
> #3  0x00007fa76d63dc82 in __GI___assert_fail (
>     assertion=assertion@entry=0x5629cea98cd5 "mr != NULL",
>     file=file@entry=0x5629cea7a884 "/home/nsrc/qemu-2.7.0/exec.c",
> line=line@entry=2967,
>     function=function@entry=0x5629cea7af00 <__PRETTY_FUNCTION__.42881>
> "address_space_unmap")
>     at assert.c:101
> #4  0x00005629ce6c0ffe in address_space_unmap (as=<optimised out>,
> buffer=<optimised out>,
>     len=<optimised out>, is_write=1, access_len=4096) at
> /home/nsrc/qemu-2.7.0/exec.c:2967
> #5  0x00005629ce743beb in virtqueue_unmap_sg
> (elem=elem@entry=0x5629d29d5290, len=len@entry=61441,
>     vq=0x5629d13186b0) at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:254
> #6  0x00005629ce744422 in virtqueue_fill (vq=vq@entry=0x5629d13186b0,
>     elem=elem@entry=0x5629d29d5290, len=61441, idx=idx@entry=0)
>     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:282
> #7  0x00005629ce7445db in virtqueue_push (vq=0x5629d13186b0,
> elem=elem@entry=0x5629d29d5290,
>     len=<optimised out>) at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:308
> #8  0x00005629ce71894d in virtio_blk_req_complete
> (req=req@entry=0x5629d29d5290,
>     status=status@entry=0 '\000') at
> /home/nsrc/qemu-2.7.0/hw/block/virtio-blk.c:58
> #9  0x00005629ce718b59 in virtio_blk_rw_complete (opaque=<optimised out>,
> ret=0)
>     at /home/nsrc/qemu-2.7.0/hw/block/virtio-blk.c:121
> #10 0x00005629ce98025a in blk_aio_complete (acb=0x5629d298f370)
>     at /home/nsrc/qemu-2.7.0/block/block-backend.c:923
> #11 0x00005629ce9efaea in coroutine_trampoline (i0=<optimised out>,
> i1=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/util/coroutine-ucontext.c:78
> #12 0x00007fa76d65a5d0 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
> #13 0x00007ffee3d75a20 in ?? ()
> #14 0x2d2d2d2d2d2d2d2d in ?? ()
> ---Type <return> to continue, or q <return> to quit---
> #15 0x00000000000000f0 in ?? ()
> #16 0x0000000000000000 in ?? ()
> 
> Aside: I see "virtqueue_unmap_sg" in the backtrace. Is this correct even for
> a non-SCSI virtio?

Great, now we know virtio-scsi is not causing this crash.

virtqueue_unmap_sg() is used by all virtio devices.  "sg" means
scatter-gather list.  It's unmapping the buffers that the guest passed
to the host.

> The command line was something like this (captured by running packer another
> time, so the ports and filenames are not exactly the same)
> 
> /usr/local/bin/qemu-system-x86_64 -m 4G -vnc [::]:59 -machine
> type=pc,accel=kvm -netdev user,id=user.0,hostfwd=tcp::2879-:22 -boot c -smp
> 8,sockets=1,cores=4,threads=2 -name vtp-nmm-201611071057.qcow2 -device
> virtio-net,netdev=user.0 -drive file=output-qemu-vtp-nmm/vtp-nmm-201611071057.qcow2,if=virtio,cache=writeback,discard=ignore,format=qcow2
> 
> 
> > The core dumps are likely to contain more clues.  If you are comfortable
> > with gdb and debugging C code you could dump the memory surround where
> > the junk value (mr) was loaded from.  Perhaps there is a hint about who
> > zeroed the memory.  In the first core dump you could start with:
> > 
> >   (gdb) up 6  # go to the dma_blk_unmap() stack frame
> >   (gdb) p *(DMAAIOCB *)0x560909ceca90
> >   (gdb) p *((DMAAIOCB *)0x560909ceca90).sg
> 
> (gdb) up 6
> #6  dma_blk_unmap (dbs=dbs@entry=0x560909ceca90) at
> /home/nsrc/qemu-2.7.0/dma-helpers.c:102
> 102            dma_memory_unmap(dbs->sg->as, dbs->iov.iov[i].iov_base,
> (gdb) p *(DMAAIOCB *)0x560909ceca90
> $1 = {common = {aiocb_info = 0x560907c15690 <dma_aiocb_info>, bs = 0x0,
>     cb = 0x56090767e250 <scsi_dma_complete>, opaque = 0x560909c2b8e0, refcnt
> = 1},
>   ctx = 0x5609087d82a0, acb = 0x0, sg = 0x560909af7430, offset = 4302675968,
>   dir = DMA_DIRECTION_FROM_DEVICE, sg_cur_index = 126, sg_cur_byte = 0, iov
> = {
>     iov = 0x560909c6e960, niov = 126, nalloc = 126, size = 1048576}, bh =
> 0x0,
>   io_func = 0x56090767d110 <scsi_dma_readv>, io_func_opaque =
> 0x560909c2b8e0}
> (gdb) p *((DMAAIOCB *)0x560909ceca90).sg
> $2 = {sg = 0x560909fab1e0, nsg = 126, nalloc = 143, size = 1048576, dev =
> 0x5609087e5630,
>   as = 0x560907e20480 <address_space_memory>}
> (gdb)
> 
> I'm comfortable with C, but don't really know what I'm looking for, nor what
> the data structures represent :-)
> 
> (gdb) p dbs->iov.niov
> $3 = 126
> (gdb) p i
> $4 = 125
> 
> ...so it appears it was in the last iteration of the loop.
> 
> (gdb) print dbs->sg->as
> $5 = (AddressSpace *) 0x560907e20480 <address_space_memory>
> (gdb) print dbs->iov.iov[i].iov_base
> $6 = (void *) 0x7f354099e000
> (gdb) print dbs->iov.iov[i].iov_len
> $7 = 8192
> (gdb) print dbs->dir
> $8 = DMA_DIRECTION_FROM_DEVICE
> 
> Unfortunately, much has been inlined:
> 
> (gdb) frame 4
> #4  0x000056090749dffe in address_space_unmap (as=<optimised out>,
> buffer=<optimised out>,
>     len=<optimised out>, is_write=1, access_len=8192) at
> /home/nsrc/qemu-2.7.0/exec.c:2967
> 2967            assert(mr != NULL);
> (gdb) print mr
> $9 = (MemoryRegion *) 0x0
> (gdb) print buffer
> $10 = <optimised out>

buffer should be 0x7f354099e000.  memory_region_from_host() returned
NULL because it was unable to find the MemoryRegion for this host
address.

Are you hotplugging and devices or adding/removing memory from the
guest?

Stefan

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 07/11/2016 11:09, Brian Candler wrote:
> On 07/11/2016 10:42, Stefan Hajnoczi wrote:
>> Let's try to isolate the cause of this crash:
>>
>> Are you able to switch -netdev user to -netdev tap so we can rule out
>> the slirp user network stack as the source of memory corruption?
> Let me try to set that up. Using packer.io, I will have to start a VM 
> by hand, and then use the 'null' builder to ssh to the existing VM 
> (whereas normally packer fires up the qemu process by itself) 


OK, I've done this.

I wrote a script which would start a standalone instance of qemu from 
libvirt, and then run packer to do the same provisioning steps over ssh 
(using the 'null' builder) as it would when running qemu by itself. I 
put this in a loop and it ran 10 times on the trot without crashing once.

These are the options which libvirt ran qemu with:

qemu-system-x86_64 -enable-kvm -name ubuntu-base -S -machine 
pc-i440fx-2.5,accel=kvm,usb=off -m 3072 -realtime mlock=off -smp 
1,sockets=1,cores=1,threads=1 -uuid 0631eb6f-94ef-4a6c-b397-b865cc2035da 
-no-user-config -nodefaults -chardev 
socket,id=charmonitor,path=/var/lib/libvirt/qemu/domain-ubuntu-base/monitor.sock,server,nowait 
-mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc 
-no-shutdown -boot strict=on -device 
piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device 
virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x7 -drive 
file=/var/lib/libvirt/images/ubuntu-base.qcow2,format=qcow2,if=none,id=drive-scsi0-0-0-0,discard=unmap 
-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 
-netdev tap,fd=27,id=hostnet0,vhost=on,vhostfd=29 -device 
virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:cc:c1:62,bus=pci.0,addr=0x3 
-chardev pty,id=charserial0 -device 
isa-serial,chardev=charserial0,id=serial0 -vnc 0.0.0.0:97 -device 
cirrus-vga,id=video0,bus=pci.0,addr=0x2 -device 
virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5 -msg timestamp=on

So either this means that using tap networking instead of user 
networking is fixing all the problems; or it is some other option which 
is different. Really I now need to run qemu with exactly the same 
settings as before, except with tap instead of user networking.

Question: is "-enable-kvm" the same as "-machine pc-xxxxx,accel=kvm", or 
do both need to be specified? I notice that packer wasn't giving both 
options, but libvirt is.

Regards,

Brian.

Re: [Qemu-devel] Crashing in tcp_close

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 474 bytes --]

On Mon, Nov 07, 2016 at 08:52:20PM +0000, Brian Candler wrote:
> Question: is "-enable-kvm" the same as "-machine pc-xxxxx,accel=kvm", or do
> both need to be specified? I notice that packer wasn't giving both options,
> but libvirt is.

No, -enable-kvm is not the same as -machine pc-xxxxx,accel=kvm in
general.

It is just equivalent to the -machine accel=kvm parameter.  You need to
specify -machine pc-xxxxx in order to get exactly the same guest
configuration.

Stefan

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 07/11/2016 20:52, Brian Candler wrote:
> So either this means that using tap networking instead of user 
> networking is fixing all the problems; or it is some other option 
> which is different. Really I now need to run qemu with exactly the 
> same settings as before, except with tap instead of user networking.

I hacked something together to run qemu directly with the right flags 
for tap networking.

packer.io now connects via ssh to the IP address which the DHCP server 
gives out for that MAC address, and runs the same provisioning code as 
before (actually a whole load of ansible scripts)

I ran it three times successfully from start to end, with no crashes. 
Hence it does appear likely then that the crashes are something to do 
with the user networking.

Regards,

Brian.


#!/bin/sh -e
cp output-qemu-ubuntu-base/ubuntu-base.qcow2 
output-null-vtp-nmm/vtp-nmm.qcow2

TAP=tap0
sudo tunctl -d tap0
sudo tunctl -u $(whoami)
sudo brctl addif br-lan $TAP
sudo ip link set dev $TAP up

echo "Starting kvm..."
/usr/local/bin/qemu-system-x86_64 \
  -machine type=pc,accel=kvm \
  -device virtio-scsi-pci,id=scsi0 \
  -device scsi-hd,bus=scsi0.0,drive=drive0 \
  -device virtio-net,netdev=network0,id=net0,mac=52:54:00:cc:c1:62 \
  -vnc [::]:24 \
  -name vtp-nmm.qcow2 \
  -boot c \
  -netdev tap,id=network0,ifname=$TAP,script=no,downscript=no \
  -drive 
if=none,file=output-null-vtp-nmm/vtp-nmm.qcow2,id=drive0,cache=writeback,discard=unmap,format=qcow2 
\
  -m 4G
# waiting for exit

sudo tunctl -d tap0

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 07/11/2016 10:42, Stefan Hajnoczi wrote:
> On Mon, Nov 07, 2016 at 08:42:17AM +0000, Brian Candler wrote:
>> >On 06/11/2016 18:04, Samuel Thibault wrote:
>>> > >Brian, could you run it with
>>> > >
>>> > >export MALLOC_CHECK_=2
>>> > >
>>> > >and also this could be useful:
>>> > >
>>> > >export MALLOC_PERTURB_=1234
>>> > >
>>> > >Also, to rule out the double-free scenario, and try to catch a buffer
>>> > >overflow coming from the socket structure itself, I have attached a
>>> > >patch which adds some debugging.
>> >
>> >Thanks. I've added the patch, and re-run the stress test.

Back to the original setup, I can still get dumps. I notice I'm now 
getting "malloc_printerr" in the backtrace, but unfortunately I don't 
get to see the actual error message. It would seem that the malloc_check 
is being done and finding an issue.  I haven't been able to get one in 
tcp_close again though :-(

Regards,

Brian.

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/local/bin/qemu-system-x86_64 -m 4G -machine 
type=pc,accel=kvm -device virt'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007eff4f3df428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
54    ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
[Current thread is 1 (Thread 0x7eff50dffa80 (LWP 13616))]
(gdb) bt
#0  0x00007eff4f3df428 in __GI_raise (sig=sig@entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00007eff4f3e102a in __GI_abort () at abort.c:89
#2  0x00007eff4f42bc1f in malloc_printerr (ar_ptr=<optimised out>, 
ptr=<optimised out>, str=<optimised out>,
     action=<optimised out>) at malloc.c:5008
#3  _int_malloc (av=av@entry=0x7eff4f76db20 <main_arena>, 
bytes=bytes@entry=89) at malloc.c:3384
#4  0x00007eff4f42c409 in malloc_check (sz=88, caller=<optimised out>) 
at hooks.c:295
#5  0x00007eff50106729 in g_malloc () from 
/lib/x86_64-linux-gnu/libglib-2.0.so.0
#6  0x0000563ca16930cf in qemu_aio_get 
(aiocb_info=aiocb_info@entry=0x563ca1841190 <blk_aio_em_aiocb_info>,
     bs=0x563ca4132f40, cb=cb@entry=0x563ca14d85e0 <dma_blk_cb>, 
opaque=opaque@entry=0x563ca5b78910)
     at /home/nsrc/qemu-2.7.0/block/io.c:2231
#7  0x0000563ca1687aa8 in blk_aio_get (opaque=0x563ca5b78910, 
cb=0x563ca14d85e0 <dma_blk_cb>, blk=0x563ca4132d70,
     aiocb_info=0x563ca1841190 <blk_aio_em_aiocb_info>) at 
/home/nsrc/qemu-2.7.0/block/block-backend.c:1477
#8  blk_aio_prwv (blk=0x563ca4132d70, offset=5278244864, bytes=4096, 
qiov=0x563ca5b78968,
     co_entry=co_entry@entry=0x563ca16872b0 <blk_aio_write_entry>, 
flags=0, cb=0x563ca14d85e0 <dma_blk_cb>,
     opaque=0x563ca5b78910) at 
/home/nsrc/qemu-2.7.0/block/block-backend.c:941
#9  0x0000563ca1687bc0 in blk_aio_pwritev (blk=<optimised out>, 
offset=<optimised out>, qiov=<optimised out>,
     flags=<optimised out>, cb=<optimised out>, opaque=<optimised out>)
     at /home/nsrc/qemu-2.7.0/block/block-backend.c:1054
#10 0x0000563ca14d8718 in dma_blk_cb (opaque=0x563ca5b78910, 
ret=<optimised out>)
     at /home/nsrc/qemu-2.7.0/dma-helpers.c:167
#11 0x0000563ca14d8bf8 in dma_blk_io (ctx=0x563ca41184a0, 
sg=sg@entry=0x563ca59a08f0,
     offset=offset@entry=5278244864, 
io_func=io_func@entry=0x563ca15a58e0 <scsi_dma_writev>,
     io_func_opaque=io_func_opaque@entry=0x563ca5c8a350, 
cb=cb@entry=0x563ca15a7250 <scsi_dma_complete>,
     opaque=0x563ca5c8a350, dir=DMA_DIRECTION_TO_DEVICE) at 
/home/nsrc/qemu-2.7.0/dma-helpers.c:222
#12 0x0000563ca15a764e in scsi_write_data (req=0x563ca5c8a350) at 
/home/nsrc/qemu-2.7.0/hw/scsi/scsi-disk.c:540
#13 0x0000563ca15ac743 in scsi_req_continue (req=req@entry=0x563ca5c8a350)
     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-bus.c:1680
#14 0x0000563ca14381a2 in virtio_scsi_handle_cmd_req_submit 
(s=0x563ca5abc1d0, req=<optimised out>)
     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:565
#15 virtio_scsi_handle_cmd_vq (s=0x563ca5abc1d0, vq=0x7eff4963f110)
     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:583
#16 0x0000563ca144a0d6 in virtio_queue_notify_vq (vq=0x7eff4963f110)
---Type <return> to continue, or q <return> to quit---
     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:1113
#17 0x0000563ca1654965 in aio_dispatch (ctx=0x563ca41184a0) at 
/home/nsrc/qemu-2.7.0/aio-posix.c:330
#18 0x0000563ca164a3ae in aio_ctx_dispatch (source=<optimised out>, 
callback=<optimised out>,
     user_data=<optimised out>) at /home/nsrc/qemu-2.7.0/async.c:234
#19 0x00007eff501011a7 in g_main_context_dispatch () from 
/lib/x86_64-linux-gnu/libglib-2.0.so.0
#20 0x0000563ca16531db in glib_pollfds_poll () at 
/home/nsrc/qemu-2.7.0/main-loop.c:213
#21 os_host_main_loop_wait (timeout=<optimised out>) at 
/home/nsrc/qemu-2.7.0/main-loop.c:258
#22 main_loop_wait (nonblocking=<optimised out>) at 
/home/nsrc/qemu-2.7.0/main-loop.c:506
#23 0x0000563ca13be431 in main_loop () at /home/nsrc/qemu-2.7.0/vl.c:1908
#24 main (argc=<optimised out>, argv=<optimised out>, envp=<optimised 
out>) at /home/nsrc/qemu-2.7.0/vl.c:4604
(gdb)

Re: [Qemu-devel] Crashing in tcp_close

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 5571 bytes --]

On Tue, Nov 08, 2016 at 09:22:25PM +0000, Brian Candler wrote:
> On 07/11/2016 10:42, Stefan Hajnoczi wrote:
> > On Mon, Nov 07, 2016 at 08:42:17AM +0000, Brian Candler wrote:
> > > >On 06/11/2016 18:04, Samuel Thibault wrote:
> > > > > >Brian, could you run it with
> > > > > >
> > > > > >export MALLOC_CHECK_=2
> > > > > >
> > > > > >and also this could be useful:
> > > > > >
> > > > > >export MALLOC_PERTURB_=1234
> > > > > >
> > > > > >Also, to rule out the double-free scenario, and try to catch a buffer
> > > > > >overflow coming from the socket structure itself, I have attached a
> > > > > >patch which adds some debugging.
> > > >
> > > >Thanks. I've added the patch, and re-run the stress test.
> 
> Back to the original setup, I can still get dumps. I notice I'm now getting
> "malloc_printerr" in the backtrace, but unfortunately I don't get to see the
> actual error message. It would seem that the malloc_check is being done and
> finding an issue.  I haven't been able to get one in tcp_close again though
> :-(

Heap corruption.  Valgrind's memcheck tool could be fruitful here:

http://valgrind.org/docs/manual/quick-start.html#quick-start.mcrun

Stefan

> Regards,
> 
> Brian.
> 
> [Thread debugging using libthread_db enabled]
> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
> Core was generated by `/usr/local/bin/qemu-system-x86_64 -m 4G -machine
> type=pc,accel=kvm -device virt'.
> Program terminated with signal SIGABRT, Aborted.
> #0  0x00007eff4f3df428 in __GI_raise (sig=sig@entry=6) at
> ../sysdeps/unix/sysv/linux/raise.c:54
> 54    ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
> [Current thread is 1 (Thread 0x7eff50dffa80 (LWP 13616))]
> (gdb) bt
> #0  0x00007eff4f3df428 in __GI_raise (sig=sig@entry=6) at
> ../sysdeps/unix/sysv/linux/raise.c:54
> #1  0x00007eff4f3e102a in __GI_abort () at abort.c:89
> #2  0x00007eff4f42bc1f in malloc_printerr (ar_ptr=<optimised out>,
> ptr=<optimised out>, str=<optimised out>,
>     action=<optimised out>) at malloc.c:5008
> #3  _int_malloc (av=av@entry=0x7eff4f76db20 <main_arena>,
> bytes=bytes@entry=89) at malloc.c:3384
> #4  0x00007eff4f42c409 in malloc_check (sz=88, caller=<optimised out>) at
> hooks.c:295
> #5  0x00007eff50106729 in g_malloc () from
> /lib/x86_64-linux-gnu/libglib-2.0.so.0
> #6  0x0000563ca16930cf in qemu_aio_get
> (aiocb_info=aiocb_info@entry=0x563ca1841190 <blk_aio_em_aiocb_info>,
>     bs=0x563ca4132f40, cb=cb@entry=0x563ca14d85e0 <dma_blk_cb>,
> opaque=opaque@entry=0x563ca5b78910)
>     at /home/nsrc/qemu-2.7.0/block/io.c:2231
> #7  0x0000563ca1687aa8 in blk_aio_get (opaque=0x563ca5b78910,
> cb=0x563ca14d85e0 <dma_blk_cb>, blk=0x563ca4132d70,
>     aiocb_info=0x563ca1841190 <blk_aio_em_aiocb_info>) at
> /home/nsrc/qemu-2.7.0/block/block-backend.c:1477
> #8  blk_aio_prwv (blk=0x563ca4132d70, offset=5278244864, bytes=4096,
> qiov=0x563ca5b78968,
>     co_entry=co_entry@entry=0x563ca16872b0 <blk_aio_write_entry>, flags=0,
> cb=0x563ca14d85e0 <dma_blk_cb>,
>     opaque=0x563ca5b78910) at
> /home/nsrc/qemu-2.7.0/block/block-backend.c:941
> #9  0x0000563ca1687bc0 in blk_aio_pwritev (blk=<optimised out>,
> offset=<optimised out>, qiov=<optimised out>,
>     flags=<optimised out>, cb=<optimised out>, opaque=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/block/block-backend.c:1054
> #10 0x0000563ca14d8718 in dma_blk_cb (opaque=0x563ca5b78910, ret=<optimised
> out>)
>     at /home/nsrc/qemu-2.7.0/dma-helpers.c:167
> #11 0x0000563ca14d8bf8 in dma_blk_io (ctx=0x563ca41184a0,
> sg=sg@entry=0x563ca59a08f0,
>     offset=offset@entry=5278244864, io_func=io_func@entry=0x563ca15a58e0
> <scsi_dma_writev>,
>     io_func_opaque=io_func_opaque@entry=0x563ca5c8a350,
> cb=cb@entry=0x563ca15a7250 <scsi_dma_complete>,
>     opaque=0x563ca5c8a350, dir=DMA_DIRECTION_TO_DEVICE) at
> /home/nsrc/qemu-2.7.0/dma-helpers.c:222
> #12 0x0000563ca15a764e in scsi_write_data (req=0x563ca5c8a350) at
> /home/nsrc/qemu-2.7.0/hw/scsi/scsi-disk.c:540
> #13 0x0000563ca15ac743 in scsi_req_continue (req=req@entry=0x563ca5c8a350)
>     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-bus.c:1680
> #14 0x0000563ca14381a2 in virtio_scsi_handle_cmd_req_submit
> (s=0x563ca5abc1d0, req=<optimised out>)
>     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:565
> #15 virtio_scsi_handle_cmd_vq (s=0x563ca5abc1d0, vq=0x7eff4963f110)
>     at /home/nsrc/qemu-2.7.0/hw/scsi/virtio-scsi.c:583
> #16 0x0000563ca144a0d6 in virtio_queue_notify_vq (vq=0x7eff4963f110)
> ---Type <return> to continue, or q <return> to quit---
>     at /home/nsrc/qemu-2.7.0/hw/virtio/virtio.c:1113
> #17 0x0000563ca1654965 in aio_dispatch (ctx=0x563ca41184a0) at
> /home/nsrc/qemu-2.7.0/aio-posix.c:330
> #18 0x0000563ca164a3ae in aio_ctx_dispatch (source=<optimised out>,
> callback=<optimised out>,
>     user_data=<optimised out>) at /home/nsrc/qemu-2.7.0/async.c:234
> #19 0x00007eff501011a7 in g_main_context_dispatch () from
> /lib/x86_64-linux-gnu/libglib-2.0.so.0
> #20 0x0000563ca16531db in glib_pollfds_poll () at
> /home/nsrc/qemu-2.7.0/main-loop.c:213
> #21 os_host_main_loop_wait (timeout=<optimised out>) at
> /home/nsrc/qemu-2.7.0/main-loop.c:258
> #22 main_loop_wait (nonblocking=<optimised out>) at
> /home/nsrc/qemu-2.7.0/main-loop.c:506
> #23 0x0000563ca13be431 in main_loop () at /home/nsrc/qemu-2.7.0/vl.c:1908
> #24 main (argc=<optimised out>, argv=<optimised out>, envp=<optimised out>)
> at /home/nsrc/qemu-2.7.0/vl.c:4604
> (gdb)
> 

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 09/11/2016 11:27, Stefan Hajnoczi wrote:
> Heap corruption.  Valgrind's memcheck tool could be fruitful here:
>
> http://valgrind.org/docs/manual/quick-start.html#quick-start.mcrun

This is really frustrating. I have been running with the following 
script instead of invoking qemu directly:

$ cat /usr/local/bin/valgrind-qemu-system-x86_64

#!/bin/sh -e
valgrind --leak-check=yes /usr/local/bin/qemu-system-x86_64 "$@"

But over more than 10 runs (some with MALLOC_xxx_ and some without) it 
did not crash once :-(

Switching back to running /usr/local/bin/qemu-system-x86_64 directly, 
and it crashed the first time:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/local/bin/qemu-system-x86_64 -netdev 
user,id=user.0,hostfwd=tcp::2373-:22'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  scsi_req_dequeue (req=0x55b22b57f930) at 
/home/nsrc/qemu-2.7.0/hw/scsi/scsi-bus.c:790
790            QTAILQ_REMOVE(&req->dev->requests, req, next);
[Current thread is 1 (Thread 0x7faece41fa80 (LWP 13702))]
(gdb) bt
#0  scsi_req_dequeue (req=0x55b22b57f930) at 
/home/nsrc/qemu-2.7.0/hw/scsi/scsi-bus.c:790
#1  0x000055b2291b5c84 in scsi_req_complete (req=0x55b22b57f930, 
status=<optimised out>)
     at /home/nsrc/qemu-2.7.0/hw/scsi/scsi-bus.c:1774
#2  0x000055b2291af2d0 in scsi_write_do_fua (r=0x55b22b57f930) at 
/home/nsrc/qemu-2.7.0/hw/scsi/scsi-disk.c:261
#3  0x000055b2290e1779 in dma_complete (ret=0, dbs=0x55b22d121770) at 
/home/nsrc/qemu-2.7.0/dma-helpers.c:115
#4  dma_blk_cb (opaque=0x55b22d121770, ret=0) at 
/home/nsrc/qemu-2.7.0/dma-helpers.c:137
#5  0x000055b22928f25a in blk_aio_complete (acb=0x55b22b0dda00) at 
/home/nsrc/qemu-2.7.0/block/block-backend.c:923
#6  0x000055b2292feaea in coroutine_trampoline (i0=<optimised out>, 
i1=<optimised out>)
     at /home/nsrc/qemu-2.7.0/util/coroutine-ucontext.c:78
#7  0x00007faecca145d0 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x00007ffde52394b0 in ?? ()
#9  0x0000000000000000 in ?? ()
(gdb)

I'm now trying valgrind again with some more options:

#!/bin/sh -e
valgrind --leak-check=yes --track-origins=yes 
--show-mismatched-frees=yes --malloc-fill=aa --free-fill=55 
/usr/local/bin/qemu-system-x86_64 "$@"

and maybe I'll give helgrind a go, but if you have any other suggestions 
please let me know.

Thanks,

Brian.

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 11/11/2016 15:02, Brian Candler wrote:
>
> But over more than 10 runs (some with MALLOC_xxx_ and some without) it 
> did not crash once :-(
Aha!! Looking carefully at valgrind output, I see some definite cases of 
use-after-free in tcp_output. Does the info below help?

Regards,

Brian.

==18350== Memcheck, a memory error detector
==18350== Copyright (C) 2002-2015, and GNU GPL'd, by Julian Seward et al.
==18350== Using Valgrind-3.11.0 and LibVEX; rerun with -h for copyright info
==18350== Command: /usr/local/bin/qemu-system-x86_64 -netdev 
user,id=user.0,hostfwd=tcp::3301-:22 -device virtio-scsi-pci,id=scsi0 
-device scsi-hd,bus=scsi0.0,drive=drive0 -device 
virtio-net,netdev=user.0 -drive 
if=none,file=output-qemu-vtp-nmm/vtp-nmm-201611111528.qcow2,id=drive0,cache=writeback,discard=unmap,format=qcow2 
-boot c -vnc [::]:46 -name vtp-nmm-201611111528.qcow2 -m 4G -machine 
type=pc,accel=kvm
==18350==
==18350== Warning: client switching stacks?  SP change: 0xffeffea78 --> 
0x6be5e48
==18350==          to suppress, use: --max-stackframe=68589554736 or greater
==18350== Warning: client switching stacks?  SP change: 0x6be5df8 --> 
0xffeffea80
==18350==          to suppress, use: --max-stackframe=68589554824 or greater
==18350== Warning: client switching stacks?  SP change: 0xffefff258 --> 
0x6be5e20
==18350==          to suppress, use: --max-stackframe=68589556792 or greater
==18350==          further instances of this message will not be shown.
==18350== Warning: noted but unhandled ioctl 0xaea3 with no 
size/direction hints.
==18350==    This could cause spurious value errors to appear.
==18350==    See README_MISSING_SYSCALL_OR_IOCTL for guidance on writing 
a proper wrapper.
==18350== Warning: set address range perms: large range [0x395db000, 
0x1397db000) (noaccess)
==18350== Warning: set address range perms: large range [0x39600000, 
0x139600000) (defined)
==18350== Thread 4:
==18350== Syscall param ioctl(generic) points to uninitialised byte(s)
==18350==    at 0x63AF357: ioctl (syscall-template.S:84)
==18350==    by 0x33AA36: kvm_vcpu_ioctl (kvm-all.c:2076)
==18350==    by 0x3F8409: kvm_put_debugregs (kvm.c:2594)
==18350==    by 0x3F8409: kvm_arch_put_registers (kvm.c:2688)
==18350==    by 0x3378AD: do_kvm_cpu_synchronize_post_init (kvm-all.c:1884)
==18350==    by 0x326901: flush_queued_work (cpus.c:1003)
==18350==    by 0x326901: qemu_wait_io_event_common (cpus.c:1022)
==18350==    by 0x32885E: qemu_kvm_wait_io_event (cpus.c:1048)
==18350==    by 0x32885E: qemu_kvm_cpu_thread_fn (cpus.c:1083)
==18350==    by 0x609D709: start_thread (pthread_create.c:333)
==18350==    by 0x63B982C: clone (clone.S:109)
==18350==  Address 0x90edb10 is on thread 4's stack
==18350==  in frame #2, created by kvm_arch_put_registers (kvm.c:2621)
==18350==  Uninitialised value was created by a stack allocation
==18350==    at 0x3F6D20: kvm_arch_put_registers (kvm.c:2621)
==18350==
==18350== Syscall param ioctl(generic) points to uninitialised byte(s)
==18350==    at 0x63AF357: ioctl (syscall-template.S:84)
==18350==    by 0x33AA36: kvm_vcpu_ioctl (kvm-all.c:2076)
==18350==    by 0x3F8409: kvm_put_debugregs (kvm.c:2594)
==18350==    by 0x3F8409: kvm_arch_put_registers (kvm.c:2688)
==18350==    by 0x33788D: do_kvm_cpu_synchronize_post_reset (kvm-all.c:1871)
==18350==    by 0x326901: flush_queued_work (cpus.c:1003)
==18350==    by 0x326901: qemu_wait_io_event_common (cpus.c:1022)
==18350==    by 0x32885E: qemu_kvm_wait_io_event (cpus.c:1048)
==18350==    by 0x32885E: qemu_kvm_cpu_thread_fn (cpus.c:1083)
==18350==    by 0x609D709: start_thread (pthread_create.c:333)
==18350==    by 0x63B982C: clone (clone.S:109)
==18350==  Address 0x90edb10 is on thread 4's stack
==18350==  in frame #2, created by kvm_arch_put_registers (kvm.c:2621)
==18350==  Uninitialised value was created by a stack allocation
==18350==    at 0x3F6D20: kvm_arch_put_registers (kvm.c:2621)
==18350==
==18350== Warning: noted but unhandled ioctl 0xaeb7 with no 
size/direction hints.
==18350==    This could cause spurious value errors to appear.
==18350==    See README_MISSING_SYSCALL_OR_IOCTL for guidance on writing 
a proper wrapper.
==18350== Syscall param ioctl(generic) points to uninitialised byte(s)
==18350==    at 0x63AF357: ioctl (syscall-template.S:84)
==18350==    by 0x33AA36: kvm_vcpu_ioctl (kvm-all.c:2076)
==18350==    by 0x3F8409: kvm_put_debugregs (kvm.c:2594)
==18350==    by 0x3F8409: kvm_arch_put_registers (kvm.c:2688)
==18350==    by 0x33AD7C: kvm_cpu_exec (kvm-all.c:1911)
==18350==    by 0x3288D7: qemu_kvm_cpu_thread_fn (cpus.c:1078)
==18350==    by 0x609D709: start_thread (pthread_create.c:333)
==18350==    by 0x63B982C: clone (clone.S:109)
==18350==  Address 0x90edaa0 is on thread 4's stack
==18350==  in frame #2, created by kvm_arch_put_registers (kvm.c:2621)
==18350==  Uninitialised value was created by a stack allocation
==18350==    at 0x3F6D20: kvm_arch_put_registers (kvm.c:2621)
==18350==
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor -1 in syscall close()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()

... lots more of these ...

==18350== Invalid read of size 4
==18350==    at 0x550B5B: if_start (if.c:230)
==18350==    by 0x552E6C: ip_output (ip_output.c:85)
==18350==    by 0x55AA31: tcp_output (tcp_output.c:469)
==18350==    by 0x558FD7: tcp_input (tcp_input.c:1386)
==18350==    by 0x55543F: slirp_input (slirp.c:867)
==18350==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==18350==    by 0x540B18: nc_sendv_compat (net.c:701)
==18350==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==18350==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==18350==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==18350==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==18350==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==18350==    by 0x5804EC: aio_bh_call (async.c:67)
==18350==    by 0x5804EC: aio_bh_poll (async.c:95)
==18350==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==18350==  Address 0x9eabec4 is 340 bytes inside a block of size 432 free'd
==18350==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==18350==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==18350==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==18350==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==18350==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==18350==    by 0x2F4430: main_loop (vl.c:1908)
==18350==    by 0x2F4430: main (vl.c:4604)
==18350==  Block was alloc'd at
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x556D42: socreate (socket.c:51)
==18350==    by 0x559580: tcp_input (tcp_input.c:432)
==18350==    by 0x55543F: slirp_input (slirp.c:867)
==18350==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==18350==    by 0x540B18: nc_sendv_compat (net.c:701)
==18350==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==18350==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==18350==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==18350==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==18350==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==18350==    by 0x5804EC: aio_bh_call (async.c:67)
==18350==    by 0x5804EC: aio_bh_poll (async.c:95)
==18350==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==18350==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==18350==
==18350== Invalid read of size 4
==18350==    at 0x550B5B: if_start (if.c:230)
==18350==    by 0x552E6C: ip_output (ip_output.c:85)
==18350==    by 0x55AA31: tcp_output (tcp_output.c:469)
==18350==    by 0x55B2D5: tcp_drop (tcp_subr.c:296)
==18350==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==18350==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==18350==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==18350==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==18350==    by 0x2F4430: main_loop (vl.c:1908)
==18350==    by 0x2F4430: main (vl.c:4604)
==18350==  Address 0x9d87f74 is 340 bytes inside a block of size 432 free'd
==18350==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==18350==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==18350==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==18350==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==18350==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==18350==    by 0x2F4430: main_loop (vl.c:1908)
==18350==    by 0x2F4430: main (vl.c:4604)
==18350==  Block was alloc'd at
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x556D42: socreate (socket.c:51)
==18350==    by 0x559580: tcp_input (tcp_input.c:432)
==18350==    by 0x55543F: slirp_input (slirp.c:867)
==18350==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==18350==    by 0x540B18: nc_sendv_compat (net.c:701)
==18350==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==18350==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==18350==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==18350==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==18350==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==18350==    by 0x5804EC: aio_bh_call (async.c:67)
==18350==    by 0x5804EC: aio_bh_poll (async.c:95)
==18350==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==18350==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==18350==
==18350== Invalid read of size 4
==18350==    at 0x550B5B: if_start (if.c:230)
==18350==    by 0x552E6C: ip_output (ip_output.c:85)
==18350==    by 0x55AA31: tcp_output (tcp_output.c:469)
==18350==    by 0x55C626: tcp_timers (tcp_timer.c:243)
==18350==    by 0x55C626: tcp_slowtimo (tcp_timer.c:89)
==18350==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==18350==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==18350==    by 0x2F4430: main_loop (vl.c:1908)
==18350==    by 0x2F4430: main (vl.c:4604)
==18350==  Address 0x8754634 is 340 bytes inside a block of size 432 free'd
==18350==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==18350==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==18350==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==18350==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==18350==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==18350==    by 0x2F4430: main_loop (vl.c:1908)
==18350==    by 0x2F4430: main (vl.c:4604)
==18350==  Block was alloc'd at
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x556D42: socreate (socket.c:51)
==18350==    by 0x559580: tcp_input (tcp_input.c:432)
==18350==    by 0x55543F: slirp_input (slirp.c:867)
==18350==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==18350==    by 0x540B18: nc_sendv_compat (net.c:701)
==18350==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==18350==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==18350==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==18350==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==18350==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==18350==    by 0x5804EC: aio_bh_call (async.c:67)
==18350==    by 0x5804EC: aio_bh_poll (async.c:95)
==18350==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==18350==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==18350==
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
==18350== Warning: invalid file descriptor 1031 in syscall socket()
... more of these
==18350== Invalid read of size 4
==18350==    at 0x550B5B: if_start (if.c:230)
==18350==    by 0x552E6C: ip_output (ip_output.c:85)
==18350==    by 0x55AA31: tcp_output (tcp_output.c:469)
==18350==    by 0x555158: slirp_pollfds_poll (slirp.c:631)
==18350==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==18350==    by 0x2F4430: main_loop (vl.c:1908)
==18350==    by 0x2F4430: main (vl.c:4604)
==18350==  Address 0xa12dd64 is 340 bytes inside a block of size 432 free'd
==18350==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==18350==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==18350==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==18350==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==18350==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==18350==    by 0x2F4430: main_loop (vl.c:1908)
==18350==    by 0x2F4430: main (vl.c:4604)
==18350==  Block was alloc'd at
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x556D42: socreate (socket.c:51)
==18350==    by 0x559580: tcp_input (tcp_input.c:432)
==18350==    by 0x55543F: slirp_input (slirp.c:867)
==18350==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==18350==    by 0x540B18: nc_sendv_compat (net.c:701)
==18350==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==18350==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==18350==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==18350==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==18350==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==18350==    by 0x5804EC: aio_bh_call (async.c:67)
==18350==    by 0x5804EC: aio_bh_poll (async.c:95)
==18350==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==18350==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==18350==
==18350==
==18350== HEAP SUMMARY:
==18350==     in use at exit: 206,196,552 bytes in 14,718 blocks
==18350==   total heap usage: 5,617,405 allocs, 5,602,687 frees, 
2,542,220,901 bytes allocated
==18350==
==18350== 8 bytes in 1 blocks are definitely lost in loss record 840 of 
4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x334895: portio_list_init (ioport.c:130)
==18350==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==18350==    by 0x45ED66: parallel_isa_realizefn (parallel.c:535)
==18350==    by 0x4634D4: device_set_realized (qdev.c:918)
==18350==    by 0x57BCBD: property_set_bool (object.c:1853)
==18350==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==18350==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==18350==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==18350==    by 0x4A05EA: parallel_init (isa-bus.c:303)
==18350==    by 0x4A05EA: parallel_hds_isa_init (isa-bus.c:314)
==18350==    by 0x38CFA7: pc_basic_device_init (pc.c:1593)
==18350==
==18350== 16 bytes in 1 blocks are definitely lost in loss record 1,848 
of 4,814
==18350==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD728: g_malloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x465F21: qemu_extend_irqs (irq.c:56)
==18350==    by 0x38CFBF: pc_basic_device_init (pc.c:1595)
==18350==    by 0x38F18A: pc_init1.constprop.0 (pc_piix.c:238)
==18350==    by 0x2F1051: main (vl.c:4467)
==18350==
==18350== 16 bytes in 1 blocks are definitely lost in loss record 1,849 
of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x334895: portio_list_init (ioport.c:130)
==18350==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==18350==    by 0x487394: i8257_realize (i8257.c:556)
==18350==    by 0x4634D4: device_set_realized (qdev.c:918)
==18350==    by 0x57BCBD: property_set_bool (object.c:1853)
==18350==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==18350==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==18350==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==18350==    by 0x487D1C: DMA_init (i8257.c:632)
==18350==    by 0x38D03B: pc_basic_device_init (pc.c:1612)
==18350==
==18350== 16 bytes in 1 blocks are definitely lost in loss record 1,850 
of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x334895: portio_list_init (ioport.c:130)
==18350==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==18350==    by 0x487394: i8257_realize (i8257.c:556)
==18350==    by 0x4634D4: device_set_realized (qdev.c:918)
==18350==    by 0x57BCBD: property_set_bool (object.c:1853)
==18350==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==18350==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==18350==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==18350==    by 0x487C8D: DMA_init (i8257.c:640)
==18350==    by 0x38D03B: pc_basic_device_init (pc.c:1612)
==18350==
==18350== 16 bytes in 1 blocks are definitely lost in loss record 1,851 
of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x334895: portio_list_init (ioport.c:130)
==18350==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==18350==    by 0x451109: isabus_fdc_realize (fdc.c:2498)
==18350==    by 0x4634D4: device_set_realized (qdev.c:918)
==18350==    by 0x57BCBD: property_set_bool (object.c:1853)
==18350==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==18350==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==18350==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==18350==    by 0x45256A: fdctrl_init_isa (fdc.c:2395)
==18350==    by 0x38D0B4: pc_basic_device_init (pc.c:1619)
==18350==
==18350== 16 bytes in 2 blocks are definitely lost in loss record 1,852 
of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x334895: portio_list_init (ioport.c:130)
==18350==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==18350==    by 0x49121F: pci_piix_init_ports (piix.c:141)
==18350==    by 0x49121F: pci_piix_ide_realize (piix.c:165)
==18350==    by 0x4D495F: pci_qdev_realize (pci.c:1966)
==18350==    by 0x4634D4: device_set_realized (qdev.c:918)
==18350==    by 0x57BCBD: property_set_bool (object.c:1853)
==18350==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==18350==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==18350==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==18350==    by 0x4D38D5: pci_create_simple_multifunction (pci.c:2017)
==18350==    by 0x4D38D5: pci_create_simple (pci.c:2028)
==18350==
==18350== 48 bytes in 2 blocks are definitely lost in loss record 2,642 
of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x334895: portio_list_init (ioport.c:130)
==18350==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==18350==    by 0x48E027: ide_init_ioport (core.c:2622)
==18350==    by 0x49121F: pci_piix_init_ports (piix.c:141)
==18350==    by 0x49121F: pci_piix_ide_realize (piix.c:165)
==18350==    by 0x4D495F: pci_qdev_realize (pci.c:1966)
==18350==    by 0x4634D4: device_set_realized (qdev.c:918)
==18350==    by 0x57BCBD: property_set_bool (object.c:1853)
==18350==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==18350==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==18350==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==18350==
==18350== 128 bytes in 1 blocks are definitely lost in loss record 4,037 
of 4,814
==18350==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x4C2FDEF: realloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD7E7: g_realloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x567B2DC: ??? (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x567C3BA: g_ptr_array_add (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x397348: crs_range_insert (acpi-build.c:745)
==18350==    by 0x397348: crs_replace_with_free_ranges (acpi-build.c:808)
==18350==    by 0x398CE2: build_dsdt (acpi-build.c:2092)
==18350==    by 0x39AA52: acpi_build (acpi-build.c:2670)
==18350==    by 0x39BB7B: acpi_setup (acpi-build.c:2873)
==18350==    by 0x38AE7A: pc_machine_done (pc.c:1270)
==18350==    by 0x626623: notifier_list_notify (notify.c:40)
==18350==    by 0x2F122B: qemu_run_machine_init_done_notifiers (vl.c:2686)
==18350==    by 0x2F122B: main (vl.c:4562)
==18350==
==18350== 128 bytes in 1 blocks are definitely lost in loss record 4,038 
of 4,814
==18350==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x4C2FDEF: realloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD7E7: g_realloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x567B2DC: ??? (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x567C3BA: g_ptr_array_add (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x397348: crs_range_insert (acpi-build.c:745)
==18350==    by 0x397348: crs_replace_with_free_ranges (acpi-build.c:808)
==18350==    by 0x398DEE: build_dsdt (acpi-build.c:2107)
==18350==    by 0x39AA52: acpi_build (acpi-build.c:2670)
==18350==    by 0x39BB7B: acpi_setup (acpi-build.c:2873)
==18350==    by 0x38AE7A: pc_machine_done (pc.c:1270)
==18350==    by 0x626623: notifier_list_notify (notify.c:40)
==18350==    by 0x2F122B: qemu_run_machine_init_done_notifiers (vl.c:2686)
==18350==    by 0x2F122B: main (vl.c:4562)
==18350==
==18350== 256 bytes in 2 blocks are definitely lost in loss record 4,231 
of 4,814
==18350==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x4C2FDEF: realloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD7E7: g_realloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x567B2DC: ??? (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x567C3BA: g_ptr_array_add (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x397348: crs_range_insert (acpi-build.c:745)
==18350==    by 0x397348: crs_replace_with_free_ranges (acpi-build.c:808)
==18350==    by 0x398CE2: build_dsdt (acpi-build.c:2092)
==18350==    by 0x39AA52: acpi_build (acpi-build.c:2670)
==18350==    by 0x39B9A0: acpi_build_update (acpi-build.c:2808)
==18350==    by 0x4CA245: fw_cfg_select (fw_cfg.c:275)
==18350==    by 0x4CADA2: fw_cfg_dma_transfer (fw_cfg.c:348)
==18350==    by 0x33D857: memory_region_write_accessor (memory.c:525)
==18350==
==18350== 256 bytes in 2 blocks are definitely lost in loss record 4,232 
of 4,814
==18350==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x4C2FDEF: realloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD7E7: g_realloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x567B2DC: ??? (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x567C3BA: g_ptr_array_add (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x397348: crs_range_insert (acpi-build.c:745)
==18350==    by 0x397348: crs_replace_with_free_ranges (acpi-build.c:808)
==18350==    by 0x398DEE: build_dsdt (acpi-build.c:2107)
==18350==    by 0x39AA52: acpi_build (acpi-build.c:2670)
==18350==    by 0x39B9A0: acpi_build_update (acpi-build.c:2808)
==18350==    by 0x4CA245: fw_cfg_select (fw_cfg.c:275)
==18350==    by 0x4CADA2: fw_cfg_dma_transfer (fw_cfg.c:348)
==18350==    by 0x33D857: memory_region_write_accessor (memory.c:525)
==18350==
==18350== 294 bytes in 27 blocks are definitely lost in loss record 
4,250 of 4,814
==18350==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x56AD728: g_malloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x56C6577: g_strndup (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x467D46: machine_class_base_init (machine.c:375)
==18350==    by 0x57C484: type_initialize.part.5 (object.c:322)
==18350==    by 0x57CA7C: type_initialize (object.c:811)
==18350==    by 0x57CA7C: object_class_foreach_tramp (object.c:798)
==18350==    by 0x569733F: g_hash_table_foreach (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==18350==    by 0x57CF17: object_class_foreach (object.c:820)
==18350==    by 0x57CFB1: object_class_get_list (object.c:874)
==18350==    by 0x410DEE: find_default_machine (vl.c:1470)
==18350==    by 0x2F033F: select_machine (vl.c:2732)
==18350==    by 0x2F033F: main (vl.c:3986)
==18350==
==18350== 304 bytes in 1 blocks are possibly lost in loss record 4,261 
of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x40136D4: allocate_dtv (dl-tls.c:322)
==18350==    by 0x40136D4: _dl_allocate_tls (dl-tls.c:539)
==18350==    by 0x609E2BE: allocate_stack (allocatestack.c:588)
==18350==    by 0x609E2BE: pthread_create@@GLIBC_2.2.5 
(pthread_create.c:539)
==18350==    by 0x61CA3D: qemu_thread_create (qemu-thread-posix.c:471)
==18350==    by 0x62AA28: rcu_init_complete (rcu.c:316)
==18350==    by 0x6B67FC: __libc_csu_init (in 
/usr/local/bin/qemu-system-x86_64)
==18350==    by 0x62D37BE: (below main) (libc-start.c:247)
==18350==
==18350== 304 bytes in 1 blocks are possibly lost in loss record 4,262 
of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x40136D4: allocate_dtv (dl-tls.c:322)
==18350==    by 0x40136D4: _dl_allocate_tls (dl-tls.c:539)
==18350==    by 0x609E2BE: allocate_stack (allocatestack.c:588)
==18350==    by 0x609E2BE: pthread_create@@GLIBC_2.2.5 
(pthread_create.c:539)
==18350==    by 0x61CA3D: qemu_thread_create (qemu-thread-posix.c:471)
==18350==    by 0x328CFC: qemu_kvm_start_vcpu (cpus.c:1405)
==18350==    by 0x328CFC: qemu_init_vcpu (cpus.c:1445)
==18350==    by 0x3C760A: x86_cpu_realizefn (cpu.c:3086)
==18350==    by 0x4634D4: device_set_realized (qdev.c:918)
==18350==    by 0x57BCBD: property_set_bool (object.c:1853)
==18350==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==18350==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==18350==    by 0x3890ED: pc_new_cpu (pc.c:1110)
==18350==    by 0x38C17B: pc_cpus_init (pc.c:1205)
==18350==
==18350== 304 bytes in 1 blocks are possibly lost in loss record 4,263 
of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x40136D4: allocate_dtv (dl-tls.c:322)
==18350==    by 0x40136D4: _dl_allocate_tls (dl-tls.c:539)
==18350==    by 0x609E2BE: allocate_stack (allocatestack.c:588)
==18350==    by 0x609E2BE: pthread_create@@GLIBC_2.2.5 
(pthread_create.c:539)
==18350==    by 0x61CA3D: qemu_thread_create (qemu-thread-posix.c:471)
==18350==    by 0x57B3EE: vnc_start_worker_thread (vnc-jobs.c:353)
==18350==    by 0x56C436: vnc_display_init (vnc.c:3159)
==18350==    by 0x56D634: vnc_init_func (vnc.c:3924)
==18350==    by 0x628839: qemu_opts_foreach (qemu-option.c:1116)
==18350==    by 0x2F11C2: main (vl.c:4545)
==18350==
==18350== 8,816 bytes in 29 blocks are possibly lost in loss record 
4,765 of 4,814
==18350==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==18350==    by 0x40136D4: allocate_dtv (dl-tls.c:322)
==18350==    by 0x40136D4: _dl_allocate_tls (dl-tls.c:539)
==18350==    by 0x609E2BE: allocate_stack (allocatestack.c:588)
==18350==    by 0x609E2BE: pthread_create@@GLIBC_2.2.5 
(pthread_create.c:539)
==18350==    by 0x61CA3D: qemu_thread_create (qemu-thread-posix.c:471)
==18350==    by 0x580B06: do_spawn_thread (thread-pool.c:135)
==18350==    by 0x580B67: worker_thread (thread-pool.c:83)
==18350==    by 0x609D709: start_thread (pthread_create.c:333)
==18350==    by 0x63B982C: clone (clone.S:109)
==18350==
==18350== LEAK SUMMARY:
==18350==    definitely lost: 1,198 bytes in 42 blocks
==18350==    indirectly lost: 0 bytes in 0 blocks
==18350==      possibly lost: 9,728 bytes in 32 blocks
==18350==    still reachable: 206,185,626 bytes in 14,644 blocks
==18350==         suppressed: 0 bytes in 0 blocks
==18350== Reachable blocks (those to which a pointer was found) are not 
shown.
==18350== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==18350==
==18350== For counts of detected and suppressed errors, rerun with: -v
==18350== ERROR SUMMARY: 784 errors from 24 contexts (suppressed: 0 from 0)

Re: [Qemu-devel] Crashing in tcp_close

[Samuel Thibault]

Hello,

Brian Candler, on Fri 11 Nov 2016 16:02:44 +0000, wrote:
> Aha!! Looking carefully at valgrind output, I see some definite cases of
> use-after-free in tcp_output. Does the info below help?

Ok, that's interesting. I however still don't see how that could happen
:)

> ==18350== Invalid read of size 4
> ==18350==    at 0x550B5B: if_start (if.c:230)
> ==18350==    by 0x552E6C: ip_output (ip_output.c:85)
> ==18350==    by 0x55AA31: tcp_output (tcp_output.c:469)
> ==18350==    by 0x558FD7: tcp_input (tcp_input.c:1386)
> ==18350==    by 0x55543F: slirp_input (slirp.c:867)
> ==18350==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
> ==18350==    by 0x540B18: nc_sendv_compat (net.c:701)
> ==18350==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
> ==18350==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
> ==18350==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
> ==18350==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
> ==18350==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
> ==18350==    by 0x5804EC: aio_bh_call (async.c:67)
> ==18350==    by 0x5804EC: aio_bh_poll (async.c:95)
> ==18350==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)

Could you increase the value given to valgrind's --num-callers= so we
can make sure the context of this call?  Here tcp_input get the buffer
being freed below from the slirp->tcb list, and sofree happens to drop
it from that list before calling free...

I'm wondering whether we have a kind of concurrency or recursivity here.

> ==18350==  Address 0x9eabec4 is 340 bytes inside a block of size 432 free'd
> ==18350==    at 0x4C2EDEB: free (in
> /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
> ==18350==    by 0x55B25E: tcp_close (tcp_subr.c:334)
> ==18350==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
> ==18350==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
> ==18350==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
> ==18350==    by 0x5891EB: main_loop_wait (main-loop.c:508)
> ==18350==    by 0x2F4430: main_loop (vl.c:1908)
> ==18350==    by 0x2F4430: main (vl.c:4604)

Samuel

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 11/11/2016 16:17, Samuel Thibault wrote:
> Could you increase the value given to valgrind's --num-callers= so we
> can make sure the context of this call?

OK: re-run with --num-callers=250. It took a few iterations, but I 
captured it again. (I have grepped out all the "invalid file descriptor" 
lines).


==1217== Memcheck, a memory error detector
==1217== Copyright (C) 2002-2015, and GNU GPL'd, by Julian Seward et al.
==1217== Using Valgrind-3.11.0 and LibVEX; rerun with -h for copyright info
==1217== Command: /usr/local/bin/qemu-system-x86_64 -device 
virtio-scsi-pci,id=scsi0 -device scsi-hd,bus=scsi0.0,drive=drive0 
-device virtio-net,netdev=user.0 -drive 
if=none,file=output-qemu-vtp-nmm/vtp-nmm-201611111946.qcow2,id=drive0,cache=writeback,discard=unmap,format=qcow2 
-boot c -vnc [::]:50 -name vtp-nmm-201611111946.qcow2 -machine 
type=pc,accel=kvm -netdev user,id=user.0,hostfwd=tcp::3972-:22 -m 4G
==1217==
==1217== Warning: client switching stacks?  SP change: 0xffeffea78 --> 
0x6be5e48
==1217==          to suppress, use: --max-stackframe=68589554736 or greater
==1217== Warning: client switching stacks?  SP change: 0x6be5df8 --> 
0xffeffea80
==1217==          to suppress, use: --max-stackframe=68589554824 or greater
==1217== Warning: client switching stacks?  SP change: 0xffefff258 --> 
0x6be5e20
==1217==          to suppress, use: --max-stackframe=68589556792 or greater
==1217==          further instances of this message will not be shown.
==1217== Warning: noted but unhandled ioctl 0xaea3 with no 
size/direction hints.
==1217==    This could cause spurious value errors to appear.
==1217==    See README_MISSING_SYSCALL_OR_IOCTL for guidance on writing 
a proper wrapper.
==1217== Warning: set address range perms: large range [0x395db000, 
0x1397db000) (noaccess)
==1217== Warning: set address range perms: large range [0x39600000, 
0x139600000) (defined)
==1217== Thread 4:
==1217== Syscall param ioctl(generic) points to uninitialised byte(s)
==1217==    at 0x63AF357: ioctl (syscall-template.S:84)
==1217==    by 0x33AA36: kvm_vcpu_ioctl (kvm-all.c:2076)
==1217==    by 0x3F8409: kvm_put_debugregs (kvm.c:2594)
==1217==    by 0x3F8409: kvm_arch_put_registers (kvm.c:2688)
==1217==    by 0x3378AD: do_kvm_cpu_synchronize_post_init (kvm-all.c:1884)
==1217==    by 0x326901: flush_queued_work (cpus.c:1003)
==1217==    by 0x326901: qemu_wait_io_event_common (cpus.c:1022)
==1217==    by 0x32885E: qemu_kvm_wait_io_event (cpus.c:1048)
==1217==    by 0x32885E: qemu_kvm_cpu_thread_fn (cpus.c:1083)
==1217==    by 0x609D709: start_thread (pthread_create.c:333)
==1217==    by 0x63B982C: clone (clone.S:109)
==1217==  Address 0x90edb10 is on thread 4's stack
==1217==  in frame #2, created by kvm_arch_put_registers (kvm.c:2621)
==1217==  Uninitialised value was created by a stack allocation
==1217==    at 0x3F6D20: kvm_arch_put_registers (kvm.c:2621)
==1217==
==1217== Syscall param ioctl(generic) points to uninitialised byte(s)
==1217==    at 0x63AF357: ioctl (syscall-template.S:84)
==1217==    by 0x33AA36: kvm_vcpu_ioctl (kvm-all.c:2076)
==1217==    by 0x3F8409: kvm_put_debugregs (kvm.c:2594)
==1217==    by 0x3F8409: kvm_arch_put_registers (kvm.c:2688)
==1217==    by 0x33788D: do_kvm_cpu_synchronize_post_reset (kvm-all.c:1871)
==1217==    by 0x326901: flush_queued_work (cpus.c:1003)
==1217==    by 0x326901: qemu_wait_io_event_common (cpus.c:1022)
==1217==    by 0x32885E: qemu_kvm_wait_io_event (cpus.c:1048)
==1217==    by 0x32885E: qemu_kvm_cpu_thread_fn (cpus.c:1083)
==1217==    by 0x609D709: start_thread (pthread_create.c:333)
==1217==    by 0x63B982C: clone (clone.S:109)
==1217==  Address 0x90edb10 is on thread 4's stack
==1217==  in frame #2, created by kvm_arch_put_registers (kvm.c:2621)
==1217==  Uninitialised value was created by a stack allocation
==1217==    at 0x3F6D20: kvm_arch_put_registers (kvm.c:2621)
==1217==
==1217== Warning: noted but unhandled ioctl 0xaeb7 with no 
size/direction hints.
==1217==    This could cause spurious value errors to appear.
==1217==    See README_MISSING_SYSCALL_OR_IOCTL for guidance on writing 
a proper wrapper.
==1217== Syscall param ioctl(generic) points to uninitialised byte(s)
==1217==    at 0x63AF357: ioctl (syscall-template.S:84)
==1217==    by 0x33AA36: kvm_vcpu_ioctl (kvm-all.c:2076)
==1217==    by 0x3F8409: kvm_put_debugregs (kvm.c:2594)
==1217==    by 0x3F8409: kvm_arch_put_registers (kvm.c:2688)
==1217==    by 0x33AD7C: kvm_cpu_exec (kvm-all.c:1911)
==1217==    by 0x3288D7: qemu_kvm_cpu_thread_fn (cpus.c:1078)
==1217==    by 0x609D709: start_thread (pthread_create.c:333)
==1217==    by 0x63B982C: clone (clone.S:109)
==1217==  Address 0x90edaa0 is on thread 4's stack
==1217==  in frame #2, created by kvm_arch_put_registers (kvm.c:2621)
==1217==  Uninitialised value was created by a stack allocation
==1217==    at 0x3F6D20: kvm_arch_put_registers (kvm.c:2621)
==1217==
==1217== Thread 1:
==1217== Invalid read of size 4
==1217==    at 0x550B5B: if_start (if.c:230)
==1217==    by 0x5550E2: slirp_pollfds_poll (slirp.c:770)
==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Address 0x97d5794 is 340 bytes inside a block of size 432 free'd
==1217==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==1217==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==1217==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==1217==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Block was alloc'd at
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x556D42: socreate (socket.c:51)
==1217==    by 0x559580: tcp_input (tcp_input.c:432)
==1217==    by 0x55543F: slirp_input (slirp.c:867)
==1217==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==1217==    by 0x540B18: nc_sendv_compat (net.c:701)
==1217==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==1217==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==1217==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==1217==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==1217==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==1217==    by 0x5804EC: aio_bh_call (async.c:67)
==1217==    by 0x5804EC: aio_bh_poll (async.c:95)
==1217==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==1217==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==1217==    by 0x56A81A6: g_main_context_dispatch (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x5891DA: glib_pollfds_poll (main-loop.c:213)
==1217==    by 0x5891DA: os_host_main_loop_wait (main-loop.c:258)
==1217==    by 0x5891DA: main_loop_wait (main-loop.c:506)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==
==1217== Invalid read of size 4
==1217==    at 0x550B5B: if_start (if.c:230)
==1217==    by 0x552E6C: ip_output (ip_output.c:85)
==1217==    by 0x55AA31: tcp_output (tcp_output.c:469)
==1217==    by 0x55B2D5: tcp_drop (tcp_subr.c:296)
==1217==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==1217==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==1217==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Address 0x975c594 is 340 bytes inside a block of size 432 free'd
==1217==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==1217==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==1217==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==1217==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Block was alloc'd at
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x556D42: socreate (socket.c:51)
==1217==    by 0x559580: tcp_input (tcp_input.c:432)
==1217==    by 0x55543F: slirp_input (slirp.c:867)
==1217==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==1217==    by 0x540B18: nc_sendv_compat (net.c:701)
==1217==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==1217==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==1217==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==1217==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==1217==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==1217==    by 0x5804EC: aio_bh_call (async.c:67)
==1217==    by 0x5804EC: aio_bh_poll (async.c:95)
==1217==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==1217==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==1217==    by 0x56A81A6: g_main_context_dispatch (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x5891DA: glib_pollfds_poll (main-loop.c:213)
==1217==    by 0x5891DA: os_host_main_loop_wait (main-loop.c:258)
==1217==    by 0x5891DA: main_loop_wait (main-loop.c:506)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==
==1217== Invalid read of size 4
==1217==    at 0x550B5B: if_start (if.c:230)
==1217==    by 0x552E6C: ip_output (ip_output.c:85)
==1217==    by 0x55AA31: tcp_output (tcp_output.c:469)
==1217==    by 0x558FD7: tcp_input (tcp_input.c:1386)
==1217==    by 0x55543F: slirp_input (slirp.c:867)
==1217==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==1217==    by 0x540B18: nc_sendv_compat (net.c:701)
==1217==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==1217==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==1217==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==1217==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==1217==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==1217==    by 0x5804EC: aio_bh_call (async.c:67)
==1217==    by 0x5804EC: aio_bh_poll (async.c:95)
==1217==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==1217==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==1217==    by 0x56A81A6: g_main_context_dispatch (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x5891DA: glib_pollfds_poll (main-loop.c:213)
==1217==    by 0x5891DA: os_host_main_loop_wait (main-loop.c:258)
==1217==    by 0x5891DA: main_loop_wait (main-loop.c:506)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Address 0x9de9f84 is 340 bytes inside a block of size 432 free'd
==1217==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==1217==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==1217==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==1217==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Block was alloc'd at
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x556D42: socreate (socket.c:51)
==1217==    by 0x559580: tcp_input (tcp_input.c:432)
==1217==    by 0x55543F: slirp_input (slirp.c:867)
==1217==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==1217==    by 0x540B18: nc_sendv_compat (net.c:701)
==1217==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==1217==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==1217==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==1217==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==1217==    by 0x36B647: virtio_net_tx_bh (virtio-net.c:1404)
==1217==    by 0x5804EC: aio_bh_call (async.c:67)
==1217==    by 0x5804EC: aio_bh_poll (async.c:95)
==1217==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==1217==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==1217==    by 0x56A81A6: g_main_context_dispatch (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x5891DA: glib_pollfds_poll (main-loop.c:213)
==1217==    by 0x5891DA: os_host_main_loop_wait (main-loop.c:258)
==1217==    by 0x5891DA: main_loop_wait (main-loop.c:506)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==
==1217== Invalid read of size 4
==1217==    at 0x550B5B: if_start (if.c:230)
==1217==    by 0x552E6C: ip_output (ip_output.c:85)
==1217==    by 0x55AA31: tcp_output (tcp_output.c:469)
==1217==    by 0x55C626: tcp_timers (tcp_timer.c:243)
==1217==    by 0x55C626: tcp_slowtimo (tcp_timer.c:89)
==1217==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Address 0xc0b59d4 is 340 bytes inside a block of size 432 free'd
==1217==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==1217==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==1217==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==1217==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Block was alloc'd at
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x556D42: socreate (socket.c:51)
==1217==    by 0x559580: tcp_input (tcp_input.c:432)
==1217==    by 0x55543F: slirp_input (slirp.c:867)
==1217==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==1217==    by 0x540B18: nc_sendv_compat (net.c:701)
==1217==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==1217==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==1217==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==1217==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==1217==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==1217==    by 0x5804EC: aio_bh_call (async.c:67)
==1217==    by 0x5804EC: aio_bh_poll (async.c:95)
==1217==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==1217==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==1217==    by 0x56A81A6: g_main_context_dispatch (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x5891DA: glib_pollfds_poll (main-loop.c:213)
==1217==    by 0x5891DA: os_host_main_loop_wait (main-loop.c:258)
==1217==    by 0x5891DA: main_loop_wait (main-loop.c:506)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==
==1217== Invalid read of size 4
==1217==    at 0x550B5B: if_start (if.c:230)
==1217==    by 0x552E6C: ip_output (ip_output.c:85)
==1217==    by 0x559E36: tcp_input (tcp_input.c:702)
==1217==    by 0x55543F: slirp_input (slirp.c:867)
==1217==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==1217==    by 0x540B18: nc_sendv_compat (net.c:701)
==1217==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==1217==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==1217==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==1217==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==1217==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==1217==    by 0x5804EC: aio_bh_call (async.c:67)
==1217==    by 0x5804EC: aio_bh_poll (async.c:95)
==1217==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==1217==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==1217==    by 0x56A81A6: g_main_context_dispatch (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x5891DA: glib_pollfds_poll (main-loop.c:213)
==1217==    by 0x5891DA: os_host_main_loop_wait (main-loop.c:258)
==1217==    by 0x5891DA: main_loop_wait (main-loop.c:506)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Address 0xbc53a34 is 340 bytes inside a block of size 432 free'd
==1217==    at 0x4C2EDEB: free (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x55B25E: tcp_close (tcp_subr.c:334)
==1217==    by 0x55C7AE: tcp_timers (tcp_timer.c:289)
==1217==    by 0x55C7AE: tcp_slowtimo (tcp_timer.c:89)
==1217==    by 0x555187: slirp_pollfds_poll (slirp.c:576)
==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==  Block was alloc'd at
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x556D42: socreate (socket.c:51)
==1217==    by 0x559580: tcp_input (tcp_input.c:432)
==1217==    by 0x55543F: slirp_input (slirp.c:867)
==1217==    by 0x54AFBF: net_slirp_receive (slirp.c:118)
==1217==    by 0x540B18: nc_sendv_compat (net.c:701)
==1217==    by 0x540B18: qemu_deliver_packet_iov (net.c:728)
==1217==    by 0x5438DA: qemu_net_queue_deliver_iov (queue.c:179)
==1217==    by 0x5438DA: qemu_net_queue_send_iov (queue.c:224)
==1217==    by 0x36B428: virtio_net_flush_tx (virtio-net.c:1282)
==1217==    by 0x36B624: virtio_net_tx_bh (virtio-net.c:1387)
==1217==    by 0x5804EC: aio_bh_call (async.c:67)
==1217==    by 0x5804EC: aio_bh_poll (async.c:95)
==1217==    by 0x58A8FF: aio_dispatch (aio-posix.c:308)
==1217==    by 0x5803AD: aio_ctx_dispatch (async.c:234)
==1217==    by 0x56A81A6: g_main_context_dispatch (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x5891DA: glib_pollfds_poll (main-loop.c:213)
==1217==    by 0x5891DA: os_host_main_loop_wait (main-loop.c:258)
==1217==    by 0x5891DA: main_loop_wait (main-loop.c:506)
==1217==    by 0x2F4430: main_loop (vl.c:1908)
==1217==    by 0x2F4430: main (vl.c:4604)
==1217==
==1217==
==1217== HEAP SUMMARY:
==1217==     in use at exit: 209,248,920 bytes in 14,656 blocks
==1217==   total heap usage: 5,622,828 allocs, 5,608,172 frees, 
2,561,007,063 bytes allocated
==1217==
==1217== 8 bytes in 1 blocks are definitely lost in loss record 1,090 of 
5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x334895: portio_list_init (ioport.c:130)
==1217==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==1217==    by 0x45ED66: parallel_isa_realizefn (parallel.c:535)
==1217==    by 0x4634D4: device_set_realized (qdev.c:918)
==1217==    by 0x57BCBD: property_set_bool (object.c:1853)
==1217==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==1217==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==1217==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==1217==    by 0x4A05EA: parallel_init (isa-bus.c:303)
==1217==    by 0x4A05EA: parallel_hds_isa_init (isa-bus.c:314)
==1217==    by 0x38CFA7: pc_basic_device_init (pc.c:1593)
==1217==    by 0x38F18A: pc_init1.constprop.0 (pc_piix.c:238)
==1217==    by 0x2F1051: main (vl.c:4467)
==1217==
==1217== 16 bytes in 1 blocks are definitely lost in loss record 2,274 
of 5,496
==1217==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD728: g_malloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x465F21: qemu_extend_irqs (irq.c:56)
==1217==    by 0x38CFBF: pc_basic_device_init (pc.c:1595)
==1217==    by 0x38F18A: pc_init1.constprop.0 (pc_piix.c:238)
==1217==    by 0x2F1051: main (vl.c:4467)
==1217==
==1217== 16 bytes in 1 blocks are definitely lost in loss record 2,275 
of 5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x334895: portio_list_init (ioport.c:130)
==1217==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==1217==    by 0x487394: i8257_realize (i8257.c:556)
==1217==    by 0x4634D4: device_set_realized (qdev.c:918)
==1217==    by 0x57BCBD: property_set_bool (object.c:1853)
==1217==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==1217==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==1217==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==1217==    by 0x487D1C: DMA_init (i8257.c:632)
==1217==    by 0x38D03B: pc_basic_device_init (pc.c:1612)
==1217==    by 0x38F18A: pc_init1.constprop.0 (pc_piix.c:238)
==1217==    by 0x2F1051: main (vl.c:4467)
==1217==
==1217== 16 bytes in 1 blocks are definitely lost in loss record 2,276 
of 5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x334895: portio_list_init (ioport.c:130)
==1217==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==1217==    by 0x487394: i8257_realize (i8257.c:556)
==1217==    by 0x4634D4: device_set_realized (qdev.c:918)
==1217==    by 0x57BCBD: property_set_bool (object.c:1853)
==1217==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==1217==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==1217==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==1217==    by 0x487C8D: DMA_init (i8257.c:640)
==1217==    by 0x38D03B: pc_basic_device_init (pc.c:1612)
==1217==    by 0x38F18A: pc_init1.constprop.0 (pc_piix.c:238)
==1217==    by 0x2F1051: main (vl.c:4467)
==1217==
==1217== 16 bytes in 1 blocks are definitely lost in loss record 2,277 
of 5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x334895: portio_list_init (ioport.c:130)
==1217==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==1217==    by 0x451109: isabus_fdc_realize (fdc.c:2498)
==1217==    by 0x4634D4: device_set_realized (qdev.c:918)
==1217==    by 0x57BCBD: property_set_bool (object.c:1853)
==1217==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==1217==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==1217==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==1217==    by 0x45256A: fdctrl_init_isa (fdc.c:2395)
==1217==    by 0x38D0B4: pc_basic_device_init (pc.c:1619)
==1217==    by 0x38F18A: pc_init1.constprop.0 (pc_piix.c:238)
==1217==    by 0x2F1051: main (vl.c:4467)
==1217==
==1217== 16 bytes in 2 blocks are definitely lost in loss record 2,278 
of 5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x334895: portio_list_init (ioport.c:130)
==1217==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==1217==    by 0x49121F: pci_piix_init_ports (piix.c:141)
==1217==    by 0x49121F: pci_piix_ide_realize (piix.c:165)
==1217==    by 0x4D495F: pci_qdev_realize (pci.c:1966)
==1217==    by 0x4634D4: device_set_realized (qdev.c:918)
==1217==    by 0x57BCBD: property_set_bool (object.c:1853)
==1217==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==1217==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==1217==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==1217==    by 0x4D38D5: pci_create_simple_multifunction (pci.c:2017)
==1217==    by 0x4D38D5: pci_create_simple (pci.c:2028)
==1217==    by 0x4914A6: pci_piix3_ide_init (piix.c:226)
==1217==    by 0x38F56C: pc_init1.constprop.0 (pc_piix.c:249)
==1217==    by 0x2F1051: main (vl.c:4467)
==1217==
==1217== 48 bytes in 2 blocks are definitely lost in loss record 3,107 
of 5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD780: g_malloc0 (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x334895: portio_list_init (ioport.c:130)
==1217==    by 0x4A0255: isa_register_portio_list (isa-bus.c:150)
==1217==    by 0x48E027: ide_init_ioport (core.c:2622)
==1217==    by 0x49121F: pci_piix_init_ports (piix.c:141)
==1217==    by 0x49121F: pci_piix_ide_realize (piix.c:165)
==1217==    by 0x4D495F: pci_qdev_realize (pci.c:1966)
==1217==    by 0x4634D4: device_set_realized (qdev.c:918)
==1217==    by 0x57BCBD: property_set_bool (object.c:1853)
==1217==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==1217==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==1217==    by 0x4622B1: qdev_init_nofail (qdev.c:358)
==1217==    by 0x4D38D5: pci_create_simple_multifunction (pci.c:2017)
==1217==    by 0x4D38D5: pci_create_simple (pci.c:2028)
==1217==    by 0x4914A6: pci_piix3_ide_init (piix.c:226)
==1217==    by 0x38F56C: pc_init1.constprop.0 (pc_piix.c:249)
==1217==    by 0x2F1051: main (vl.c:4467)
==1217==
==1217== 128 bytes in 1 blocks are definitely lost in loss record 4,710 
of 5,496
==1217==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x4C2FDEF: realloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD7E7: g_realloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x567B2DC: ??? (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x567C3BA: g_ptr_array_add (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x397348: crs_range_insert (acpi-build.c:745)
==1217==    by 0x397348: crs_replace_with_free_ranges (acpi-build.c:808)
==1217==    by 0x398CE2: build_dsdt (acpi-build.c:2092)
==1217==    by 0x39AA52: acpi_build (acpi-build.c:2670)
==1217==    by 0x39BB7B: acpi_setup (acpi-build.c:2873)
==1217==    by 0x38AE7A: pc_machine_done (pc.c:1270)
==1217==    by 0x626623: notifier_list_notify (notify.c:40)
==1217==    by 0x2F122B: qemu_run_machine_init_done_notifiers (vl.c:2686)
==1217==    by 0x2F122B: main (vl.c:4562)
==1217==
==1217== 128 bytes in 1 blocks are definitely lost in loss record 4,711 
of 5,496
==1217==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x4C2FDEF: realloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD7E7: g_realloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x567B2DC: ??? (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x567C3BA: g_ptr_array_add (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x397348: crs_range_insert (acpi-build.c:745)
==1217==    by 0x397348: crs_replace_with_free_ranges (acpi-build.c:808)
==1217==    by 0x398DEE: build_dsdt (acpi-build.c:2107)
==1217==    by 0x39AA52: acpi_build (acpi-build.c:2670)
==1217==    by 0x39BB7B: acpi_setup (acpi-build.c:2873)
==1217==    by 0x38AE7A: pc_machine_done (pc.c:1270)
==1217==    by 0x626623: notifier_list_notify (notify.c:40)
==1217==    by 0x2F122B: qemu_run_machine_init_done_notifiers (vl.c:2686)
==1217==    by 0x2F122B: main (vl.c:4562)
==1217==
==1217== 256 bytes in 2 blocks are definitely lost in loss record 4,922 
of 5,496
==1217==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x4C2FDEF: realloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD7E7: g_realloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x567B2DC: ??? (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x567C3BA: g_ptr_array_add (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x397348: crs_range_insert (acpi-build.c:745)
==1217==    by 0x397348: crs_replace_with_free_ranges (acpi-build.c:808)
==1217==    by 0x398CE2: build_dsdt (acpi-build.c:2092)
==1217==    by 0x39AA52: acpi_build (acpi-build.c:2670)
==1217==    by 0x39B9A0: acpi_build_update (acpi-build.c:2808)
==1217==    by 0x4CA245: fw_cfg_select (fw_cfg.c:275)
==1217==    by 0x4CADA2: fw_cfg_dma_transfer (fw_cfg.c:348)
==1217==    by 0x33D857: memory_region_write_accessor (memory.c:525)
==1217==    by 0x33BDC7: access_with_adjusted_size (memory.c:586)
==1217==    by 0x33FC1B: memory_region_dispatch_write (memory.c:1275)
==1217==    by 0x2FB7B8: address_space_write_continue (exec.c:2544)
==1217==    by 0x2FB7B8: address_space_write (exec.c:2601)
==1217==    by 0x33AE3F: kvm_handle_io (kvm-all.c:1791)
==1217==    by 0x33AE3F: kvm_cpu_exec (kvm-all.c:1955)
==1217==    by 0x3288D7: qemu_kvm_cpu_thread_fn (cpus.c:1078)
==1217==    by 0x609D709: start_thread (pthread_create.c:333)
==1217==    by 0x63B982C: clone (clone.S:109)
==1217==
==1217== 256 bytes in 2 blocks are definitely lost in loss record 4,923 
of 5,496
==1217==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x4C2FDEF: realloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD7E7: g_realloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x567B2DC: ??? (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x567C3BA: g_ptr_array_add (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x397348: crs_range_insert (acpi-build.c:745)
==1217==    by 0x397348: crs_replace_with_free_ranges (acpi-build.c:808)
==1217==    by 0x398DEE: build_dsdt (acpi-build.c:2107)
==1217==    by 0x39AA52: acpi_build (acpi-build.c:2670)
==1217==    by 0x39B9A0: acpi_build_update (acpi-build.c:2808)
==1217==    by 0x4CA245: fw_cfg_select (fw_cfg.c:275)
==1217==    by 0x4CADA2: fw_cfg_dma_transfer (fw_cfg.c:348)
==1217==    by 0x33D857: memory_region_write_accessor (memory.c:525)
==1217==    by 0x33BDC7: access_with_adjusted_size (memory.c:586)
==1217==    by 0x33FC1B: memory_region_dispatch_write (memory.c:1275)
==1217==    by 0x2FB7B8: address_space_write_continue (exec.c:2544)
==1217==    by 0x2FB7B8: address_space_write (exec.c:2601)
==1217==    by 0x33AE3F: kvm_handle_io (kvm-all.c:1791)
==1217==    by 0x33AE3F: kvm_cpu_exec (kvm-all.c:1955)
==1217==    by 0x3288D7: qemu_kvm_cpu_thread_fn (cpus.c:1078)
==1217==    by 0x609D709: start_thread (pthread_create.c:333)
==1217==    by 0x63B982C: clone (clone.S:109)
==1217==
==1217== 294 bytes in 27 blocks are definitely lost in loss record 4,940 
of 5,496
==1217==    at 0x4C2DB8F: malloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x56AD728: g_malloc (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x56C6577: g_strndup (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x467D46: machine_class_base_init (machine.c:375)
==1217==    by 0x57C484: type_initialize.part.5 (object.c:322)
==1217==    by 0x57CA7C: type_initialize (object.c:811)
==1217==    by 0x57CA7C: object_class_foreach_tramp (object.c:798)
==1217==    by 0x569733F: g_hash_table_foreach (in 
/lib/x86_64-linux-gnu/libglib-2.0.so.0.4800.1)
==1217==    by 0x57CF17: object_class_foreach (object.c:820)
==1217==    by 0x57CFB1: object_class_get_list (object.c:874)
==1217==    by 0x410DEE: find_default_machine (vl.c:1470)
==1217==    by 0x2F033F: select_machine (vl.c:2732)
==1217==    by 0x2F033F: main (vl.c:3986)
==1217==
==1217== 304 bytes in 1 blocks are possibly lost in loss record 4,951 of 
5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x40136D4: allocate_dtv (dl-tls.c:322)
==1217==    by 0x40136D4: _dl_allocate_tls (dl-tls.c:539)
==1217==    by 0x609E2BE: allocate_stack (allocatestack.c:588)
==1217==    by 0x609E2BE: pthread_create@@GLIBC_2.2.5 (pthread_create.c:539)
==1217==    by 0x61CA3D: qemu_thread_create (qemu-thread-posix.c:471)
==1217==    by 0x62AA28: rcu_init_complete (rcu.c:316)
==1217==    by 0x6B67FC: __libc_csu_init (in 
/usr/local/bin/qemu-system-x86_64)
==1217==    by 0x62D37BE: (below main) (libc-start.c:247)
==1217==
==1217== 304 bytes in 1 blocks are possibly lost in loss record 4,952 of 
5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x40136D4: allocate_dtv (dl-tls.c:322)
==1217==    by 0x40136D4: _dl_allocate_tls (dl-tls.c:539)
==1217==    by 0x609E2BE: allocate_stack (allocatestack.c:588)
==1217==    by 0x609E2BE: pthread_create@@GLIBC_2.2.5 (pthread_create.c:539)
==1217==    by 0x61CA3D: qemu_thread_create (qemu-thread-posix.c:471)
==1217==    by 0x328CFC: qemu_kvm_start_vcpu (cpus.c:1405)
==1217==    by 0x328CFC: qemu_init_vcpu (cpus.c:1445)
==1217==    by 0x3C760A: x86_cpu_realizefn (cpu.c:3086)
==1217==    by 0x4634D4: device_set_realized (qdev.c:918)
==1217==    by 0x57BCBD: property_set_bool (object.c:1853)
==1217==    by 0x57FAE0: object_property_set_qobject (qom-qobject.c:27)
==1217==    by 0x57D9AF: object_property_set_bool (object.c:1156)
==1217==    by 0x3890ED: pc_new_cpu (pc.c:1110)
==1217==    by 0x38C17B: pc_cpus_init (pc.c:1205)
==1217==    by 0x38EFC3: pc_init1.constprop.0 (pc_piix.c:150)
==1217==    by 0x2F1051: main (vl.c:4467)
==1217==
==1217== 304 bytes in 1 blocks are possibly lost in loss record 4,953 of 
5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x40136D4: allocate_dtv (dl-tls.c:322)
==1217==    by 0x40136D4: _dl_allocate_tls (dl-tls.c:539)
==1217==    by 0x609E2BE: allocate_stack (allocatestack.c:588)
==1217==    by 0x609E2BE: pthread_create@@GLIBC_2.2.5 (pthread_create.c:539)
==1217==    by 0x61CA3D: qemu_thread_create (qemu-thread-posix.c:471)
==1217==    by 0x57B3EE: vnc_start_worker_thread (vnc-jobs.c:353)
==1217==    by 0x56C436: vnc_display_init (vnc.c:3159)
==1217==    by 0x56D634: vnc_init_func (vnc.c:3924)
==1217==    by 0x628839: qemu_opts_foreach (qemu-option.c:1116)
==1217==    by 0x2F11C2: main (vl.c:4545)
==1217==
==1217== 4,864 bytes in 16 blocks are possibly lost in loss record 5,433 
of 5,496
==1217==    at 0x4C2FB55: calloc (in 
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==1217==    by 0x40136D4: allocate_dtv (dl-tls.c:322)
==1217==    by 0x40136D4: _dl_allocate_tls (dl-tls.c:539)
==1217==    by 0x609E2BE: allocate_stack (allocatestack.c:588)
==1217==    by 0x609E2BE: pthread_create@@GLIBC_2.2.5 (pthread_create.c:539)
==1217==    by 0x61CA3D: qemu_thread_create (qemu-thread-posix.c:471)
==1217==    by 0x580B06: do_spawn_thread (thread-pool.c:135)
==1217==    by 0x580B67: worker_thread (thread-pool.c:83)
==1217==    by 0x609D709: start_thread (pthread_create.c:333)
==1217==    by 0x63B982C: clone (clone.S:109)
==1217==
==1217== LEAK SUMMARY:
==1217==    definitely lost: 1,198 bytes in 42 blocks
==1217==    indirectly lost: 0 bytes in 0 blocks
==1217==      possibly lost: 5,776 bytes in 19 blocks
==1217==    still reachable: 209,241,946 bytes in 14,595 blocks
==1217==         suppressed: 0 bytes in 0 blocks
==1217== Reachable blocks (those to which a pointer was found) are not 
shown.
==1217== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==1217==
==1217== For counts of detected and suppressed errors, rerun with: -v
==1217== ERROR SUMMARY: 464 errors from 24 contexts (suppressed: 0 from 0)

Re: [Qemu-devel] Crashing in tcp_close

[Samuel Thibault]

[-- Attachment #1: Type: text/plain, Size: 819 bytes --]

Brian Candler, on Fri 11 Nov 2016 20:53:12 +0000, wrote:
> On 11/11/2016 16:17, Samuel Thibault wrote:
> >Could you increase the value given to valgrind's --num-callers= so we
> >can make sure the context of this call?
> 
> OK: re-run with --num-callers=250. It took a few iterations, but I captured
> it again. (I have grepped out all the "invalid file descriptor" lines).

Thanks!

> ==1217== Thread 1:
> ==1217== Invalid read of size 4
> ==1217==    at 0x550B5B: if_start (if.c:230)
> ==1217==    by 0x5550E2: slirp_pollfds_poll (slirp.c:770)
> ==1217==    by 0x5891EB: main_loop_wait (main-loop.c:508)
> ==1217==    by 0x2F4430: main_loop (vl.c:1908)
> ==1217==    by 0x2F4430: main (vl.c:4604)

Ooh, I see.  Now it's obvious, now that it's not coming from the tcb
loop :) Could you try the attached patch?

Samuel

[-- Attachment #2: patch --]
[-- Type: text/plain, Size: 415 bytes --]

diff --git a/slirp/socket.c b/slirp/socket.c
index 280050a..1a50d30 100644
--- a/slirp/socket.c
+++ b/slirp/socket.c
@@ -66,6 +66,13 @@ void
 sofree(struct socket *so)
 {
   Slirp *slirp = so->slirp;
+  struct mbuf *ifm;
+
+  for (ifm = slirp->next_m; ifm; ifm = ifm->ifq_next) {
+    if (ifm->ifq_so == so) {
+      ifm->ifq_so = NULL;
+    }
+  }
 
   if (so->so_emu==EMU_RSH && so->extra) {
 	sofree(so->extra);

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 11/11/2016 22:09, Samuel Thibault wrote:
> Ooh, I see.  Now it's obvious, now that it's not coming from the tcb
> loop:)  Could you try the attached patch?

It looks like it now goes into an infinite loop when a connection is 
closed. Packer output stopped here:

...

2016/11/12 09:29:04 ui:     qemu: Get:33 
http://us.archive.ubuntu.com/ubuntu xenial-backports/universe i386 
Packages [2,212 B]
     qemu: Get:33 http://us.archive.ubuntu.com/ubuntu 
xenial-backports/universe i386 Packages [2,212 B]
2016/11/12 09:29:04 ui:     qemu: Get:34 
http://us.archive.ubuntu.com/ubuntu xenial-backports/universe 
Translation-en [1,144 B]
     qemu: Get:34 http://us.archive.ubuntu.com/ubuntu 
xenial-backports/universe Translation-en [1,144 B]

top shows:

  4828 nsrc      20   0 4688860 796236   9136 R 100.0  2.4 0:30.16 
qemu-system-x86

strace doesn't show anything:

# strace -p 4828
strace: Process 4828 attached
strace: [ Process PID=4828 runs in x32 mode. ]

So I sent a SIGABRT, here is the backtrace:

Core was generated by `/usr/local/bin/qemu-system-x86_64 -m 4G -drive 
if=none,file=output-qemu-vtp-nmm'.
Program terminated with signal SIGABRT, Aborted.
#0  sofree (so=so@entry=0x564b181fc940) at 
/home/nsrc/qemu-2.7.0/slirp/socket.c:74
74        if (ifm->ifq_so == so) {
[Current thread is 1 (Thread 0x7f9308610a80 (LWP 4828))]
(gdb) bt
#0  sofree (so=so@entry=0x564b181fc940) at 
/home/nsrc/qemu-2.7.0/slirp/socket.c:74
#1  0x0000564b14d8428f in tcp_close (tp=tp@entry=0x564b16287590)
     at /home/nsrc/qemu-2.7.0/slirp/tcp_subr.c:334
#2  0x0000564b14d82dc8 in tcp_input (m=0x564b182d9000, iphlen=<optimised 
out>, inso=inso@entry=0x0,
     af=af@entry=2) at /home/nsrc/qemu-2.7.0/slirp/tcp_input.c:1201
#3  0x0000564b14d7bc2b in ip_input (m=<optimised out>, 
m@entry=0x564b182d9000)
     at /home/nsrc/qemu-2.7.0/slirp/ip_input.c:206
#4  0x0000564b14d7e440 in slirp_input (slirp=<optimised out>, 
pkt=0x7f92ba4fc412 "RU\n",
     pkt_len=pkt_len@entry=54) at /home/nsrc/qemu-2.7.0/slirp/slirp.c:867
#5  0x0000564b14d73fc0 in net_slirp_receive (nc=<optimised out>, 
buf=<optimised out>, size=54)
     at /home/nsrc/qemu-2.7.0/net/slirp.c:118
#6  0x0000564b14d69b19 in nc_sendv_compat (flags=<optimised out>, 
iovcnt=<optimised out>,
     iov=0x7ffd6b417e00, nc=0x564b16293840) at 
/home/nsrc/qemu-2.7.0/net/net.c:701
#7  qemu_deliver_packet_iov (sender=<optimised out>, flags=<optimised 
out>, iov=0x7ffd6b417e00,
     iovcnt=<optimised out>, opaque=0x564b16293840) at 
/home/nsrc/qemu-2.7.0/net/net.c:728
#8  0x0000564b14d6c8db in qemu_net_queue_deliver_iov (iovcnt=1, 
iov=0x7ffd6b417e00, flags=0,
     sender=0x564b17db26d0, queue=0x564b16293290) at 
/home/nsrc/qemu-2.7.0/net/queue.c:179
#9  qemu_net_queue_send_iov (queue=0x564b16293290, 
sender=0x564b17db26d0, flags=flags@entry=0,
     iov=iov@entry=0x7ffd6b417e00, iovcnt=iovcnt@entry=1,
     sent_cb=sent_cb@entry=0x564b14b94690 <virtio_net_tx_complete>)
     at /home/nsrc/qemu-2.7.0/net/queue.c:224
#10 0x0000564b14d6a5f3 in qemu_sendv_packet_async (sender=<optimised out>,
     iov=iov@entry=0x7ffd6b417e00, iovcnt=iovcnt@entry=1,
     sent_cb=sent_cb@entry=0x564b14b94690 <virtio_net_tx_complete>)
     at /home/nsrc/qemu-2.7.0/net/net.c:764
#11 0x0000564b14b94429 in virtio_net_flush_tx (q=q@entry=0x564b17db2600)
     at /home/nsrc/qemu-2.7.0/hw/net/virtio-net.c:1282
#12 0x0000564b14b94625 in virtio_net_tx_bh (opaque=0x564b17db2600)
     at /home/nsrc/qemu-2.7.0/hw/net/virtio-net.c:1387
#13 0x0000564b14da951d in aio_bh_call (bh=<optimised out>) at 
/home/nsrc/qemu-2.7.0/async.c:67
#14 aio_bh_poll (ctx=ctx@entry=0x564b1627e060) at 
/home/nsrc/qemu-2.7.0/async.c:95
---Type <return> to continue, or q <return> to quit---
#15 0x0000564b14db3930 in aio_dispatch (ctx=0x564b1627e060) at 
/home/nsrc/qemu-2.7.0/aio-posix.c:308
#16 0x0000564b14da93de in aio_ctx_dispatch (source=<optimised out>, 
callback=<optimised out>,
     user_data=<optimised out>) at /home/nsrc/qemu-2.7.0/async.c:234
#17 0x00007f93079121a7 in g_main_context_dispatch () from 
/lib/x86_64-linux-gnu/libglib-2.0.so.0
#18 0x0000564b14db220b in glib_pollfds_poll () at 
/home/nsrc/qemu-2.7.0/main-loop.c:213
#19 os_host_main_loop_wait (timeout=<optimised out>) at 
/home/nsrc/qemu-2.7.0/main-loop.c:258
#20 main_loop_wait (nonblocking=<optimised out>) at 
/home/nsrc/qemu-2.7.0/main-loop.c:506
#21 0x0000564b14b1d431 in main_loop () at /home/nsrc/qemu-2.7.0/vl.c:1908
#22 main (argc=<optimised out>, argv=<optimised out>, envp=<optimised out>)
     at /home/nsrc/qemu-2.7.0/vl.c:4604
(gdb)

Regards,

Brian.

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 12/11/2016 09:33, Brian Candler wrote:
> So I sent a SIGABRT, here is the backtrace:

And here is some state from the core dump:

(gdb) print so
$1 = (struct socket *) 0x564b181fc940
(gdb) print *so
$2 = {so_next = 0x564b18258c60, so_prev = 0x564b181fcb00, canary1 = 
-559038737, s = 28,
   pollfds_idx = -1, slirp = 0x564b16293a70, so_m = 0x0, so_ti = 
0x564b182d9070, so_urgc = 0, fhost = {
     ss = {ss_family = 2,
       __ss_padding = 
"\fFd@\000\361\000\000\000\000\000\000\000\000^\000\000\000n", '\000' 
<repeats 19 times>, 
"\330|Ak\375\177\000\000\002\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\070|Ak\375\177\000\000\271\022\262\024KV\000\000\001\000\000\000\000\000\000\000\312\031\262\024KV\000\000\340|Ak\375\177\000\000\000\021\002?\323fZ\345\000\220-\030KV\000", 
__ss_align = 94880472217585}, sin = {
       sin_family = 2, sin_port = 17932, sin_addr = {s_addr = 4043325540},
       sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 
2, sin6_port = 17932,
       sin6_flowinfo = 4043325540, sin6_addr = {__in6_u = {
           __u6_addr8 = 
"\000\000\000\000\000\000\000\000^\000\000\000n\000\000", __u6_addr16 = 
{0, 0,
             0, 0, 94, 0, 110, 0}, __u6_addr32 = {0, 0, 94, 110}}}, 
sin6_scope_id = 0}}, lhost = {
     ss = {ss_family = 2,
       __ss_padding = 
"\231\246\n\000\002\017\000\000\000\000\000\000\000\000\320\t\032\030KV\000\000\000\021\002?\323fZ\345\214\304+\030KV\000\000\320\t\032\030KV\000\000\000\304+\030KV\000\000Y[\330\024KV\000\000\000|Ak\375\177\000\000\061\000\000\000KV\000\000\061\000\000\000KV\000\000\024\000\000\000\000\000\000\000E\000E\000\251\246\000@@\021{\355\n\000\002\017\n\000\002\003\000\000\000",
       __ss_align = 313532612711}, sin = {sin_family = 2, sin_port = 
42649, sin_addr = {
         s_addr = 251789322}, sin_zero = 
"\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2,
       sin6_port = 42649, sin6_flowinfo = 251789322, sin6_addr = 
{__in6_u = {
           __u6_addr8 = 
"\000\000\000\000\000\000\000\000\320\t\032\030KV\000", __u6_addr16 = {0, 0,
             0, 0, 2512, 6170, 22091, 0}, __u6_addr32 = {0, 0, 
404359632, 22091}}},
       sin6_scope_id = 1057100032}}, so_iptos = 0 '\000', so_emu = 0 
'\000', so_type = 0 '\000',
   so_state = 1, so_tcpcb = 0x0, so_expire = 0, so_queued = 0, 
so_nqueued = 0, so_rcv = {sb_cc = 0,
     sb_datalen = 9000, sb_wptr = 0x564b162898c0 "\200u(\026KV",
     sb_rptr = 0x564b162898c0 "\200u(\026KV", sb_data = 0x564b162898c0 
"\200u(\026KV"}, so_snd = {
     sb_cc = 0, sb_datalen = 9000,
     sb_wptr = 0x564b162e8034 
"/3\204|\244n\217;\257|\260nMshG\351\373\211w\205\241\252\364Z\343", 
<incomplete sequence \307>,
     sb_rptr = 0x564b162e8034 
"/3\204|\244n\217;\257|\260nMshG\351\373\211w\205\241\252\364Z\343", 
<incomplete sequence \307>, sb_data = 0x564b162e7cc0 "\260\230(\026KV"}, 
extra = 0x0,
---Type <return> to continue, or q <return> to quit---
   canary2 = -1103113299}
(gdb) print so->slirp
$3 = (Slirp *) 0x564b16293a70
(gdb) print *(so->slirp)
$4 = {entry = {tqe_next = 0x0, tqe_prev = 0x564b154961a0 
<slirp_instances>}, time_fasttimo = 0,
   last_slowtimo = 549524, do_slowtimo = true, in_enabled = true, 
in6_enabled = true, vnetwork_addr = {
     s_addr = 131082}, vnetwork_mask = {s_addr = 16777215}, vhost_addr = 
{s_addr = 33685514},
   vprefix_addr6 = {__in6_u = {__u6_addr8 = "\376\300", '\000' <repeats 
13 times>, __u6_addr16 = {
         49406, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {49406, 0, 0, 0}}}, 
vprefix_len = 64 '@',
   vhost_addr6 = {__in6_u = {__u6_addr8 = "\376\300", '\000' <repeats 13 
times>, "\002",
       __u6_addr16 = {49406, 0, 0, 0, 0, 0, 0, 512}, __u6_addr32 = 
{49406, 0, 0, 33554432}}},
   vdhcp_startaddr = {s_addr = 251789322}, vnameserver_addr = {s_addr = 
50462730},
   vnameserver_addr6 = {__in6_u = {__u6_addr8 = "\376\300", '\000' 
<repeats 13 times>, "\003",
       __u6_addr16 = {49406, 0, 0, 0, 0, 0, 0, 768}, __u6_addr32 = 
{49406, 0, 0, 50331648}}},
   client_ipaddr = {s_addr = 0}, client_hostname = '\000' <repeats 32 
times>, restricted = 0,
   exec_list = 0x0, m_freelist = {qh_link = 0x564b182c9600, qh_rlink = 
0x564b182c9600}, m_usedlist = {
     qh_link = 0x564b182d9000, qh_rlink = 0x564b182bfa00}, mbuf_alloced 
= 11, if_fastq = {
     qh_link = 0x564b16293b30, qh_rlink = 0x564b16293b30}, if_batchq = 
{qh_link = 0x564b16293b40,
     qh_rlink = 0x564b16293b40}, next_m = 0x564b16293b40, if_start_busy 
= false, ipq = {frag_link = {
       next = 0x0, prev = 0x0}, ip_link = {next = 0x564b16293b69, prev = 
0x564b16293b69},
     ipq_ttl = 0 '\000', ipq_p = 0 '\000', ipq_id = 0, ipq_src = {s_addr 
= 0}, ipq_dst = {
       s_addr = 0}}, ip_id = 2123, bootp_clients = {{allocated = 1, 
macaddr = "RT\000\022\064V"}, {
       allocated = 0, macaddr = "\000\000\000\000\000"} <repeats 15 
times>}, bootp_filename = 0x0,
   vdnssearch_len = 0, vdnssearch = 0x0, tcb = {so_next = 
0x564b182be7c0, so_prev = 0x564b16295ce0,
     canary1 = 0, s = 0, pollfds_idx = 0, slirp = 0x0, so_m = 0x0, so_ti 
= 0x0, so_urgc = 0, fhost = {
       ss = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, 
__ss_align = 0}, sin = {
         sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0},
         sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family 
= 0, sin6_port = 0,
         sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' 
<repeats 15 times>,
             __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 
0, 0, 0}}},
         sin6_scope_id = 0}}, lhost = {ss = {ss_family = 0, __ss_padding 
= '\000' <repeats 117 times>,
         __ss_align = 0}, sin = {sin_family = 0, sin_port = 0, sin_addr 
= {s_addr = 0},
         sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family 
= 0, sin6_port = 0,
         sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' 
<repeats 15 times>,
             __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 
0, 0, 0}}},
---Type <return> to continue, or q <return> to quit---
         sin6_scope_id = 0}}, so_iptos = 0 '\000', so_emu = 0 '\000', 
so_type = 0 '\000',
     so_state = 0, so_tcpcb = 0x0, so_expire = 0, so_queued = 0, 
so_nqueued = 0, so_rcv = {sb_cc = 0,
       sb_datalen = 0, sb_wptr = 0x0, sb_rptr = 0x0, sb_data = 0x0}, 
so_snd = {sb_cc = 0,
       sb_datalen = 0, sb_wptr = 0x0, sb_rptr = 0x0, sb_data = 0x0}, 
extra = 0x0, canary2 = 0},
   tcp_last_so = 0x564b16293c20, tcp_iss = 1920001, tcp_now = 25, udb = 
{so_next = 0x564b182be600,
     so_prev = 0x564b182bdc00, canary1 = 0, s = 0, pollfds_idx = 0, 
slirp = 0x0, so_m = 0x0,
     so_ti = 0x0, so_urgc = 0, fhost = {ss = {ss_family = 0,
         __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}, sin 
= {sin_family = 0,
         sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = 
"\000\000\000\000\000\000\000"}, sin6 = {
         sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = 
{__in6_u = {
             __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 
0, 0, 0, 0, 0, 0, 0},
             __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, lhost = 
{ss = {ss_family = 0,
         __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}, sin 
= {sin_family = 0,
         sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = 
"\000\000\000\000\000\000\000"}, sin6 = {
         sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = 
{__in6_u = {
             __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 
0, 0, 0, 0, 0, 0, 0},
             __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, so_iptos 
= 0 '\000',
     so_emu = 0 '\000', so_type = 0 '\000', so_state = 0, so_tcpcb = 
0x0, so_expire = 0,
     so_queued = 0, so_nqueued = 0, so_rcv = {sb_cc = 0, sb_datalen = 0, 
sb_wptr = 0x0, sb_rptr = 0x0,
       sb_data = 0x0}, so_snd = {sb_cc = 0, sb_datalen = 0, sb_wptr = 
0x0, sb_rptr = 0x0,
       sb_data = 0x0}, extra = 0x0, canary2 = 0}, udp_last_so = 
0x564b182d7e00, icmp = {
     so_next = 0x564b16293f98, so_prev = 0x564b16293f98, canary1 = 0, s 
= 0, pollfds_idx = 0,
     slirp = 0x0, so_m = 0x0, so_ti = 0x0, so_urgc = 0, fhost = {ss = 
{ss_family = 0,
         __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}, sin 
= {sin_family = 0,
         sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = 
"\000\000\000\000\000\000\000"}, sin6 = {
         sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = 
{__in6_u = {
             __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 
0, 0, 0, 0, 0, 0, 0},
             __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, lhost = 
{ss = {ss_family = 0,
         __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}, sin 
= {sin_family = 0,
         sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = 
"\000\000\000\000\000\000\000"}, sin6 = {
         sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = 
{__in6_u = {
---Type <return> to continue, or q <return> to quit---
             __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 
0, 0, 0, 0, 0, 0, 0},
             __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, so_iptos 
= 0 '\000',
     so_emu = 0 '\000', so_type = 0 '\000', so_state = 0, so_tcpcb = 
0x0, so_expire = 0,
     so_queued = 0, so_nqueued = 0, so_rcv = {sb_cc = 0, sb_datalen = 0, 
sb_wptr = 0x0, sb_rptr = 0x0,
       sb_data = 0x0}, so_snd = {sb_cc = 0, sb_datalen = 0, sb_wptr = 
0x0, sb_rptr = 0x0,
       sb_data = 0x0}, extra = 0x0, canary2 = 0}, icmp_last_so = 
0x564b16293f98, tftp_prefix = 0x0,
   tftp_sessions = {{slirp = 0x0, filename = 0x0, fd = 0, client_addr = 
{ss_family = 0,
         __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}, 
client_port = 0, block_nr = 0,
       timestamp = 0} <repeats 20 times>}, arp_table = {table = {{ar_hrd 
= 0, ar_pro = 0,
         ar_hln = 0 '\000', ar_pln = 0 '\000', ar_op = 0, ar_sha = 
"RT\000\022\064V",
         ar_sip = 251789322, ar_tha = "\000\000\000\000\000", ar_tip = 
0}, {ar_hrd = 0, ar_pro = 0,
         ar_hln = 0 '\000', ar_pln = 0 '\000', ar_op = 0, ar_sha = 
"\000\000\000\000\000", ar_sip = 0,
         ar_tha = "\000\000\000\000\000", ar_tip = 0} <repeats 15 
times>}, next_victim = 1},
   ndp_table = {table = {{eth_addr = "RT\000\022\064V", ip_addr = 
{__in6_u = {
             __u6_addr8 = 
"\376\200\000\000\000\000\000\000PT\000\377\376\022\064V", __u6_addr16 = {
               33022, 0, 0, 0, 21584, 65280, 4862, 22068}, __u6_addr32 = 
{33022, 0, 4278211664,
               1446253310}}}}, {eth_addr = "\000\000\000\000\000", 
ip_addr = {__in6_u = {
             __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 
0, 0, 0, 0, 0, 0, 0},
             __u6_addr32 = {0, 0, 0, 0}}}} <repeats 15 times>}, 
next_victim = 1},
   grand = 0x564b162951c0, ra_timer = 0x564b162932d0, opaque = 
0x564b16293840}
(gdb) print so->slirp->next_m
$5 = (struct mbuf *) 0x564b16293b40
(gdb) print *(so->slirp->next_m)
$6 = {m_next = 0x564b16293b40, m_prev = 0x564b16293b40, m_nextpkt = 
0x564b16293b40, m_prevpkt = 0x0,
   m_flags = 0, m_size = 0, m_so = 0x564b16293b6900,
   m_data = 0x564b16293b6900 <error: Cannot access memory at address 
0x564b16293b6900>, m_len = 0,
   slirp = 0x84b000000000000, resolution_requested = true, 
expiration_date = 0, m_ext = 0x0,
   m_dat = 0x564b16293ba0 ""}
(gdb) print so->slirp->next_m->ifq_so
There is no member named ifq_so.
(gdb) print (so->slirp->next_m)->ifq_next
There is no member named ifq_next.

<< digs through code >> Ah OK, ifq_so and ifq_next are macros.

(gdb) print so->slirp->next_m->m_so
$8 = (struct socket *) 0x564b16293b6900
(gdb) print *(so->slirp->next_m->m_so)
Cannot access memory at address 0x564b16293b6900
(gdb) print so->slirp->next_m->m_next
$9 = (struct mbuf *) 0x564b16293b40
(gdb) print *(so->slirp->next_m->m_next)
$10 = {m_next = 0x564b16293b40, m_prev = 0x564b16293b40, m_nextpkt = 
0x564b16293b40, m_prevpkt = 0x0,
   m_flags = 0, m_size = 0, m_so = 0x564b16293b6900,
   m_data = 0x564b16293b6900 <error: Cannot access memory at address 
0x564b16293b6900>, m_len = 0,
   slirp = 0x84b000000000000, resolution_requested = true, 
expiration_date = 0, m_ext = 0x0,
   m_dat = 0x564b16293ba0 ""}

Looks corrupt if pointers are outside accessible areas.

(gdb) print so
$16 = (struct socket *) 0x564b181fc940
(gdb) print so->slirp->next_m->m_so
$17 = (struct socket *) 0x564b16293b6900
(gdb) print so->slirp->next_m->m_next->m_so
$18 = (struct socket *) 0x564b16293b6900
(gdb) print so->slirp->next_m->m_next->m_next->m_so
$19 = (struct socket *) 0x564b16293b6900
(gdb) print so->slirp->next_m->m_next->m_next->m_next->m_so
$20 = (struct socket *) 0x564b16293b6900
(gdb)

There's the infinite loop.

Regards,

Brian.

Re: [Qemu-devel] Crashing in tcp_close

[Samuel Thibault]

[-- Attachment #1: Type: text/plain, Size: 385 bytes --]

Hello,

Brian Candler, on Sat 12 Nov 2016 09:33:55 +0000, wrote:
> On 11/11/2016 22:09, Samuel Thibault wrote:
> >Ooh, I see.  Now it's obvious, now that it's not coming from the tcb
> >loop:)  Could you try the attached patch?
> 
> It looks like it now goes into an infinite loop when a connection is closed.

Oops, sorry, my patch was completely bogus, here is a proper one.

Samuel

[-- Attachment #2: patch --]
[-- Type: text/plain, Size: 707 bytes --]

diff --git a/slirp/socket.c b/slirp/socket.c
index 280050a..6c18971 100644
--- a/slirp/socket.c
+++ b/slirp/socket.c
@@ -66,6 +66,23 @@ void
 sofree(struct socket *so)
 {
   Slirp *slirp = so->slirp;
+  struct mbuf *ifm;
+
+  for (ifm = (struct mbuf *) slirp->if_fastq.qh_link;
+       (struct quehead *) ifm != &slirp->if_fastq;
+       ifm = ifm->ifq_next) {
+    if (ifm->ifq_so == so) {
+      ifm->ifq_so = NULL;
+    }
+  }
+
+  for (ifm = (struct mbuf *) slirp->if_batchq.qh_link;
+       (struct quehead *) ifm != &slirp->if_batchq;
+       ifm = ifm->ifq_next) {
+    if (ifm->ifq_so == so) {
+      ifm->ifq_so = NULL;
+    }
+  }
 
   if (so->so_emu==EMU_RSH && so->extra) {
 	sofree(so->extra);

Re: [Qemu-devel] Crashing in tcp_close

[Brian Candler]

On 12/11/2016 10:44, Samuel Thibault wrote:
> Oops, sorry, my patch was completely bogus, here is a proper one.

Excellent.

I've run the original build process 18 times (each run takes about 25 
minutes) without valgrind, and it hasn't crashed once. So this looks 
good. Thank you!

Regards,

Brian.

Re: [Qemu-devel] Crashing in tcp_close

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 494 bytes --]

On Sun, Nov 13, 2016 at 11:55:16AM +0000, Brian Candler wrote:
> On 12/11/2016 10:44, Samuel Thibault wrote:
> > Oops, sorry, my patch was completely bogus, here is a proper one.
> 
> Excellent.
> 
> I've run the original build process 18 times (each run takes about 25
> minutes) without valgrind, and it hasn't crashed once. So this looks good.
> Thank you!

Excellent work guys!  Glad that the issue was solved.

Thanks for sticking around to debug this issue, Brian!

Stefan

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]