Re: [Qemu-devel] [Bug 824650] [NEW] Latest GIT assert error in arp_table.c

[Roy Tam]

2011/9/15 Jan Kiszka <address@hidden>:
> On 2011-09-15 12:53, Roy Tam wrote:
>> 2011/9/15 Jan Kiszka <address@hidden>:
>>> On 2011-09-15 09:38, Roy Tam wrote:
>>>> 2011/9/15 Jan Kiszka <address@hidden>:
>>>>> On 2011-09-15 06:11, Roy Tam wrote:
>>>>>> 2011/8/12 Nigel Horne <address@hidden>:
>>>>>>> Public bug reported:
>>>>>>>
>>>>>>> The latest git version of qemu (commit
>>>>>>> 8cc7c3952d4d0a681d8d4c3ac89a206a5bfd7f00) crashes after a few minutes.
>>>>>>> All was fine up to a few days ago.  This is wth both x86 and sparc
>>>>>>> emulation, on an x86_64 host.
>>>>>>>
>>>>>>> e.g. qemu-system-sparc -drive
>>>>>>> file=netbsd5.0.2-sparc,index=0,media=disk,cache=unsafe -m 256 -boot c
>>>>>>> -nographic -redir tcp:2232::22:
>>>>>>>
>>>>>>>  qemu-system-sparc: slirp/arp_table.c:75: arp_table_search: Assertion
>>>>>>> `(ip_addr & (__extension__ ({ register unsigned int __v, __x = (~(0xf <<
>>>>>>> 28)); if (__builtin_constant_p (__x)) __v = ((((__x) & 0xff000000) >>
>>>>>>> 24) | (((__x) & 0x00ff0000) >> 8) | (((__x) & 0x0000ff00) << 8) |
>>>>>>> (((__x) & 0x000000ff) << 24)); else __asm__ ("bswap %0" : "=r" (__v) :
>>>>>>> "0" (__x)); __v; }))) != 0' failed.
>>>>>>>
>>>>>>> ** Affects: qemu
>>>>>>>     Importance: Undecided
>>>>>>>         Status: New
>>>>>>>
>>>>>>> --
>>>>>>> You received this bug notification because you are a member of qemu-
>>>>>>> devel-ml, which is subscribed to QEMU.
>>>>>>> https://bugs.launchpad.net/bugs/824650
>>>>>>>
>>>>>>> Title:
>>>>>>>  Latest GIT assert error in arp_table.c
>>>>>>>
>>>>>>> Status in QEMU:
>>>>>>>  New
>>>>>>>
>>>>>>> Bug description:
>>>>>>>  The latest git version of qemu (commit
>>>>>>>  8cc7c3952d4d0a681d8d4c3ac89a206a5bfd7f00) crashes after a few minutes.
>>>>>>>  All was fine up to a few days ago.  This is wth both x86 and sparc
>>>>>>>  emulation, on an x86_64 host.
>>>>>>>
>>>>>>>  e.g. qemu-system-sparc -drive
>>>>>>>  file=netbsd5.0.2-sparc,index=0,media=disk,cache=unsafe -m 256 -boot c
>>>>>>>  -nographic -redir tcp:2232::22:
>>>>>>>
>>>>>>>   qemu-system-sparc: slirp/arp_table.c:75: arp_table_search: Assertion
>>>>>>>  `(ip_addr & (__extension__ ({ register unsigned int __v, __x = (~(0xf
>>>>>>>  << 28)); if (__builtin_constant_p (__x)) __v = ((((__x) & 0xff000000)
>>>>>>>  >> 24) | (((__x) & 0x00ff0000) >> 8) | (((__x) & 0x0000ff00) << 8) |
>>>>>>>  (((__x) & 0x000000ff) << 24)); else __asm__ ("bswap %0" : "=r" (__v) :
>>>>>>>  "0" (__x)); __v; }))) != 0' failed.
>>>>>>>
>>>>>>> To manage notifications about this bug go to:
>>>>>>> https://bugs.launchpad.net/qemu/+bug/824650/+subscriptions
>>>>>>>
>>>>>>>
>>>>>>
>>>>>> I'm hitting same assertion too.
>>>>>>
>>>>>> Assertion failed: (ip_addr & htonl(~(0xf << 28))) != 0, file
>>>>>> slirp/arp_table.c, line 75
>>>>>>
>>>>>> Environment: Win XP SP3 host, MinGW gcc 4.3.3-tdm-1
>>>>>> Build: qemu.git rev 44520db10b1b92f272348ab7028e7afc68ac3edf
>>>>>> CommandLine: qemu -hda e:\xp.vmdk -soundhw sb16 -m 320 -localtime -usb
>>>>>> -usbdevice tablet -net user -net nic,model=ne2k_pci -drive
>>>>>> if=none,id=usbstick,file=e:\4m.img -device
>>>>>> usb-storage,bus=usb.0,drive=usbstick
>>>>>
>>>>> Same request here: Please try to catch a bit more context (backtrace,
>>>>> variable states etc.) via gdb. Or if you have a way to reproduce the
>>>>> issue, let me know the details.
>>>>>
>>>>> Thanks,
>>>>> Jan
>>>>>
>>>>>
>>>>
>>>> Hope it helps.
>>>>
>>>> C:\msys\home\User\qemu>gdb --args i386-softmmu\qemu-system-i386.exe
>>>> -hda i386-softmmu\xp.vmdk -soundhw sb16 -m 320 -localtime -usb
>>>> -usbdevice tablet -net user -net nic,model=ne2k_pci -L pc-bios
>>>> GNU gdb (GDB) 7.3
>>>> Copyright (C) 2011 Free Software Foundation, Inc.
>>>> License GPLv3+: GNU GPL version 3 or later 
>>>> <http://gnu.org/licenses/gpl.html>
>>>> This is free software: you are free to change and redistribute it.
>>>> There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
>>>> and "show warranty" for details.
>>>> This GDB was configured as "mingw32".
>>>> For bug reporting instructions, please see:
>>>> <http://www.gnu.org/software/gdb/bugs/>...
>>>> Reading symbols from 
>>>> C:\msys\home\User\qemu/i386-softmmu\qemu-system-i386.exe...
>>>> done.
>>>> (gdb) list:arp_table.c:75
>>>> No source file named .
>>>> (gdb) list arp_table.c:75
>>>> 70
>>>> 71          DEBUG_CALL("arp_table_search");
>>>> 72          DEBUG_ARG("ip = 0x%x", ip_addr);
>>>> 73
>>>> 74          /* Check 0.0.0.0/8 invalid source-only addresses */
>>>> 75          assert((ip_addr & htonl(~(0xf << 28))) != 0);
>>>> 76
>>>> 77          /* If broadcast address */
>>>> 78          if (ip_addr == 0xffffffff || ip_addr == broadcast_addr) {
>>>> 79              /* return Ethernet broadcast address */
>>>> (gdb) break arp_table.c:75
>>>> Breakpoint 1 at 0x4b7ee1: file slirp/arp_table.c, line 75.
>>>> (gdb) r
>>>> Starting program:
>>>> C:\msys\home\User\qemu/i386-softmmu\qemu-system-i386.exe -hda
>>>> i386-softmmu\\xp.vmdk -soundhw sb16 -m 320 -localtime -usb -usbdevice
>>>> tablet -net user -net nic,model=ne2k_pci -L pc-bios
>>>> [New Thread 8744.0x313c]
>>>> [New Thread 8744.0x3098]
>>>> [New Thread 8744.0x2108]
>>>> [New Thread 8744.0x2c4c]
>>>> [New Thread 8744.0x365c]
>>>> sb16: warning: command 0xf,1 is not truly understood yet
>>>> sb16: warning: command 0xe,2 is not truly understood yet
>>>> [Switching to Thread 8744.0x2108]
>>>>
>>>> Breakpoint 1, arp_table_search (slirp=0x19f7380, ip_addr=4294967295,
>>>>     out_ethaddr=0x20af64a "\311\001") at slirp/arp_table.c:75
>>>> 75          assert((ip_addr & htonl(~(0xf << 28))) != 0);
>>>> (gdb) c
>>>> Continuing.
>>>> [New Thread 8744.0x36d4]
>>>> [Switching to Thread 8744.0x313c]
>>>>
>>>> Breakpoint 1, arp_table_search (slirp=0x19f7380, ip_addr=0,
>>>>     out_ethaddr=0x22f642 "\"") at slirp/arp_table.c:75
>>>> 75          assert((ip_addr & htonl(~(0xf << 28))) != 0);
>>>> (gdb) bt
>>>> #0  arp_table_search (slirp=0x19f7380, ip_addr=0, out_ethaddr=0x22f642 
>>>> "\"")
>>>>     at slirp/arp_table.c:75
>>>> #1  0x004bafbd in if_encap (slirp=0x19f7488, ifm=0x1caf5a8)
>>>>     at slirp/slirp.c:709
>>>> #2  0x004b8a73 in if_start (slirp=0x19f7380) at slirp/if.c:210
>>>> #3  0x004b9c9e in ip_output (so=0x1caf5a8, m0=0x0) at slirp/ip_output.c:84
>>>> #4  0x004bf737 in tcp_output (tp=0x21f57d0) at slirp/tcp_output.c:456
>>>> #5  0x004c09ad in tcp_drop (tp=0x21f57d0, err=0) at slirp/tcp_subr.c:225
>>>> #6  0x004c1182 in tcp_timers (timer=<optimized out>, tp=<optimized out>)
>>>>     at slirp/tcp_timer.c:287
>>>> #7  tcp_slowtimo (slirp=0x0) at slirp/tcp_timer.c:88
>>>> #8  0x004bb6f1 in slirp_select_poll (readfds=0x22fae0, writefds=0x22f9dc,
>>>>     xfds=0x22f8d8, select_error=2291816) at slirp/slirp.c:433
>>>> #9  0x0048fb87 in main_loop_wait (nonblocking=0)
>>>>     at C:/msys/home/User/qemu/vl.c:1436
>>>> #10 0x00490d10 in main_loop () at C:/msys/home/User/qemu/vl.c:1466
>>>> #11 qemu_main (argc=0, argv=0x19f5100, envp=0x0)
>>>>     at C:/msys/home/User/qemu/vl.c:3453
>>>> #12 0x0049322d in SDL_main (argc=17, argv=0x19f5100)
>>>>     at C:/msys/home/User/qemu/vl.c:102
>>>> #13 0x005eb784 in console_main ()
>>>> #14 0x005eb844 in address@hidden ()
>>>> #15 0x005eb068 in main ()
>>>> (gdb) c
>>>> Continuing.
>>>> Assertion failed: (ip_addr & htonl(~(0xf << 28))) != 0, file 
>>>> slirp/arp_table.c,
>>>> line 75
>>>>
>>>> This application has requested the Runtime to terminate it in an unusual 
>>>> way.
>>>> Please contact the application's support team for more information.
>>>> [Inferior 1 (process 8744) exited with code 03]
>>>> (gdb)
>>>
>>> I suspect a half-baked TCP socket times out, and slirp tries to
>>> terminate this socket by sending a FIN to an invalid client IP. Pending
>>> bug that now surfaced thanks to the assertion.
>>>
>>> To confirm this, you could check the state of the socket, specifically
>>> the tcpip header template.
>>>
>>
>> Please explain this in detail for doing it in Win32 environment. Is
>> there a DEBUG #define that can debug slirp?
>
> After hitting the assert with gdb, go to frame 4 and print *tp.
> Interesting is the content of t_template.
>

Here you go.

sb16: warning: command 0xf,1 is not truly understood yet
sb16: warning: command 0xe,2 is not truly understood yet
[Switching to Thread 13840.0x3140]

Breakpoint 1, arp_table_search (slirp=0x19f7380, ip_addr=4294967295,
    out_ethaddr=0x20af64a "") at slirp/arp_table.c:75
75      //    assert((ip_addr & htonl(~(0xf << 28))) != 0);
(gdb) c
Continuing.
[New Thread 13840.0x31b8]
[Switching to Thread 13840.0x3628]

Breakpoint 1, arp_table_search (slirp=0x19f7380, ip_addr=0,
    out_ethaddr=0x22f642 "\"") at slirp/arp_table.c:75
75      //    assert((ip_addr & htonl(~(0xf << 28))) != 0);
(gdb) bt
#0  arp_table_search (slirp=0x19f7380, ip_addr=0, out_ethaddr=0x22f642 "\"")
    at slirp/arp_table.c:75
#1  0x004bafbd in if_encap (slirp=0x19f7488, ifm=0x2255978)
    at slirp/slirp.c:709
#2  0x004b8a73 in if_start (slirp=0x19f7380) at slirp/if.c:210
#3  0x004b9c9e in ip_output (so=0x2255978, m0=0x0) at slirp/ip_output.c:84
#4  0x004bf737 in tcp_output (tp=0x1cac848) at slirp/tcp_output.c:456
#5  0x004c09ad in tcp_drop (tp=0x1cac848, err=0) at slirp/tcp_subr.c:225
#6  0x004c1182 in tcp_timers (timer=<optimized out>, tp=<optimized out>)
    at slirp/tcp_timer.c:287
#7  tcp_slowtimo (slirp=0x0) at slirp/tcp_timer.c:88
#8  0x004bb6f1 in slirp_select_poll (readfds=0x22fae0, writefds=0x22f9dc,
    xfds=0x22f8d8, select_error=2291816) at slirp/slirp.c:433
#9  0x0048fb87 in main_loop_wait (nonblocking=0)
    at C:/msys/home/User/qemu/vl.c:1436
#10 0x00490d10 in main_loop () at C:/msys/home/User/qemu/vl.c:1466
#11 qemu_main (argc=0, argv=0x19f5100, envp=0x0)
    at C:/msys/home/User/qemu/vl.c:3453
#12 0x0049322d in SDL_main (argc=17, argv=0x19f5100)
    at C:/msys/home/User/qemu/vl.c:102
#13 0x005eb784 in console_main ()
#14 0x005eb844 in address@hidden ()
#15 0x005eb068 in main ()
(gdb) frame 4
#4  0x004bf737 in tcp_output (tp=0x1cac848) at slirp/tcp_output.c:456
456             error = ip_output(so, m);
(gdb) print *tp
$1 = {seg_next = 0x1cac848, seg_prev = 0x1cac848, t_state = 0, t_timer = {0,
    0, 0, 0}, t_rxtshift = 0, t_rxtcur = 12, t_dupacks = 0, t_maxseg = 1460,
  t_force = 0 '\000', t_flags = 0, t_template = {ti_i = {ih_mbuf = {
        mptr = 0x0, dummy = 0}, ih_x1 = 0 '\000', ih_pr = 0 '\000',
      ih_len = 0, ih_src = {S_un = {S_un_b = {s_b1 = 0 '\000',
            s_b2 = 0 '\000', s_b3 = 0 '\000', s_b4 = 0 '\000'}, S_un_w = {
            s_w1 = 0, s_w2 = 0}, S_addr = 0}}, ih_dst = {S_un = {S_un_b = {
            s_b1 = 0 '\000', s_b2 = 0 '\000', s_b3 = 0 '\000',
            s_b4 = 0 '\000'}, S_un_w = {s_w1 = 0, s_w2 = 0}, S_addr = 0}}},
    ti_t = {th_sport = 0, th_dport = 0, th_seq = 0, th_ack = 0,
      th_x2 = 0 '\000', th_off = 0 '\000', th_flags = 0 '\000', th_win = 0,
      th_sum = 0, th_urp = 0}}, t_socket = 0x2182af0, snd_una = 0,
  snd_nxt = 0, snd_up = 0, snd_wl1 = 0, snd_wl2 = 0, iss = 0, snd_wnd = 0,
  rcv_wnd = 8192, rcv_nxt = 0, rcv_up = 0, irs = 0, rcv_adv = 0, snd_max = 0,
  snd_cwnd = 1460, snd_ssthresh = 1073725440, t_idle = 149, t_rtt = 0,
  t_rtseq = 0, t_srtt = 0, t_rttvar = 24, t_rttmin = 2, max_sndwnd = 0,
  t_oobflags = 0 '\000', t_iobc = 0 '\000', t_softerror = 0,
  snd_scale = 0 '\000', rcv_scale = 0 '\000', request_r_scale = 0 '\000',
  requested_s_scale = 0 '\000', ts_recent = 0, ts_recent_age = 0,
  last_ack_sent = 0}
(gdb)

>>
>>> Obviously, this triggers early in the boot, right? Maybe you could debug
>>> the lifecycle of the affected socket?
>>>
>>
>> No. The guest XP SP3 goes into the desktop, waits for the automatic
>> update tray icon appear and start to download updates(almost 5~6
>> minutes), then QEMU assertion fails.
>
> Too bad...
>
> Jan
>
>