Re: gpsmon crashes in ncurses code

[SZIGETVÁRI János]

Hi Thomas,

Gary E. Miller over at the gpsd mailing list added some extra locking to gpsmon as you requested, but unfortunately gpsmon still crashes, now at a slightly different place:

#0  0x76e3e888 in waddch_literal (win=0x1536c8, ch=2097184) at ../ncurses/./base/lib_addch.c:391
        x = 2
        y = 2
        line = 0x153730
#1  0x76e3ea0c in waddch_nosync (win=0x1536c8, ch=32) at ../ncurses/./base/lib_addch.c:443
        x = 21
        y = -1
        t = 32
        sp = 0x112430
        s = 0x76e1f3d8 <unctrl_blob+96> " "
        tabsize = 8
#2  0x76e3ed18 in _nc_waddch_nosync (win=0x1536c8, c=32) at ../ncurses/./base/lib_addch.c:529
No locals.
#3  0x76e3f088 in waddnstr (win=0x1536c8, astr=0x14e0f8 " 0", n=1) at ../ncurses/./base/lib_addstr.c:70
        ch = 32
        str = 0x14e0f9 "0"
        code = 0
#4  0x76e56a7c in vw_printw (win=0x1536c8, fmt=0xc4c30 "%2d", argp=...) at ../ncurses/./base/lib_printw.c:164
        buf = 0x14e0f8 " 0"
        code = -1
        sp = 0x112430
#5  0x76e568e4 in mvwprintw (win=0x1536c8, y=2, x=1, fmt=0xc4c30 "%2d") at ../ncurses/./base/lib_printw.c:127
        argp = {__ap = 0x7eff6f00}
        code = 0
        argq = {__ap = 0x7eff6f00}
#6  0x000238ac in ubx_initialize () at monitor_ubx.c:34
        i = 0
#7  0x00014c94 in switch_type (devtype=0xcc79c <driver_ubx>) at gpsmon.c:535
        leftover = 0
        trial = 0xed310 <monitor_objects+36>
        newobject = 0xed310 <monitor_objects+36>
#8  0x00014ef0 in select_packet_monitor (device=0xf4030 <session>) at gpsmon.c:581
        active_type = 0xcc79c <driver_ubx>
        last_type = 19
#9  0x00015970 in gpsmon_hook (device=0xf4030 <session>, changed=19494547352520246) at gpsmon.c:820
        buf = "\264\004\006\000\000\000\000\000\000\000\000\000h\360\377~\003\000\000\000\020\357\377~\350\357\377~le\":true,\"json\":false,\"nmea\":false,\"raw\":2,\"scaled\":false,\"timing\":false,\"split24\":false,\"pps\":true}\n\000\060\067\",\"activated\":\"2020-05-15T09:41:51.233Z\",\"flags\":1,\"native\":1,\"bps\":"...
        ts_buf1 = "\b\000\000\000\200*\f\000\000\000\000\000\070\060\001\000\000\000\000\000\000"
        ts_buf2 = "\340X\306v\324\316\377~\200*\f\000\000\000\000\000\070\060\001\000\000"
        __PRETTY_FUNCTION__ = "gpsmon_hook"
#10 0x00061fa4 in gpsd_multipoll (data_ready=true, device=0xf4030 <session>, handler=0x15520 <gpsmon_hook>, reawake_time=0) at libgpsd_core.c:1844
        changed = 19494547352520246
        fragments = 1
#11 0x00017880 in main (argc=1, argv=0x7efff264) at gpsmon.c:1409
        efds = {fds_bits = {0 <repeats 32 times>}}
        option = -1
        explanation = 0x0
        bailout = 0
        matches = 0
        nmea = false
        all_fds = {fds_bits = {9, 0 <repeats 31 times>}}
        rfds = {fds_bits = {8, 0 <repeats 31 times>}}
        maxfd = 3
        inbuf = "x\365\377v\300W\306vH\246\377v\000\000\000\000\000\360\377~0y\377v \304\374v\205\317c\t\003\000\000\000x\365\377vjz\334v0y\377v(\360\377~\220\302\374v\020n\375v\001\000\000\000 \304\374v\026\000\000\000\360\304\374vx\365\377v"

        nocurses = false
        activated = 3

As we haven't managed to make considerable progress, I am giving up on this.

I would like to thank you for your efforts that you put into solving this.

Through this I have learned a lot about the steps one can take to better debug free software.

Best Regards,

János

--

Janos SZIGETVARI
RHCE, License no. 150-053-692

LinkedIn: linkedin.com/in/janosszigetvari

__@__˚V˚
Make the switch to open (source) applications, protocols, formats now:
- windows -> Linux, iexplore -> Firefox, msoffice -> LibreOffice
- msn -> jabber protocol (Pidgin, Google Talk)
- mp3 -> ogg, wmv -> ogg, jpg -> png, doc/xls/ppt -> odt/ods/odp

Thomas Dickey <address@hidden> ezt írta (időpont: 2020. ápr. 25., Szo, 21:22):

On Mon, Apr 20, 2020 at 02:36:10PM +0200, SZIGETVÁRI János wrote:
> Hi Thomas,
>
> Thomas Dickey <address@hidden> ezt írta (időpont: 2020. ápr. 18., Szo,
> 22:22):
>
> > What I can see looks normal, but the problem is the "text" pointer,
> > which is null.
> >
> > _line is a pointer to an array of line data
> > (which is where "line" comes from, above):
> >
> > In gdb, you should be able to do
> >
> >         print win->_line[0]
> >         print win->_line[1]
> >         print win->_line[2]     <---- the one that's bad
> >         print win->_line[3]
> >
> > Perhaps the whole array has some problem.  I'd look at that first,
> > and try to see if it was actually initialized.
> >
>
> It looks more-or-less okay. Only the third line seems off with its
> null-pointer:
>
> (gdb) define chtype_print
> Type commands for definition of "chtype_print".
> End with a line saying just "end".
> >echo "
> >set $c = (unsigned int *)$arg0
> >set $d = (char) ( (*$c) & (A_CHARTEXT) )
> >while ( $d )
>  >  if ( $d > 0x7f )
>   >    printf "[%x]", $d
>   >  else
>   >    printf "%c", $d
>   >  end
>  >  set $c++
>  >  set $d = (char) ( (*$c) & (A_CHARTEXT) )
>  >end
> >echo "\n
> >end
> ...
> (gdb) chtype_print  (win->_line[0]->text)
> "lqqqqqqqqqqqqqqqqqqqqqqqqqqk
>      "
> (gdb) chtype_print  (win->_line[1]->text)
> "xCh PRN  Az  El S/N Flag U x
>      "
> (gdb) chtype_print  (win->_line[2]->text)
> "Cannot access memory at address 0x0
> (gdb) chtype_print  (win->_line[3]->text)
> "x                          x
>      "
> (gdb) print win->_line[0]
> $22 = {text = 0x211bf8, firstchar = 0, lastchar = 27, oldindex = 0}
> (gdb) print win->_line[1]
> $23 = {text = 0x211d40, firstchar = 0, lastchar = 27, oldindex = 0}
> (gdb) print win->_line[2]
> $24 = {text = 0x0, firstchar = 0, lastchar = 27, oldindex = 0}
> (gdb) print win->_line[3]
> $25 = {text = 0x2127f8, firstchar = 0, lastchar = 27, oldindex = 0}
>
> ...and if you configured using "--with-trace", you could turn on the
> > trace feature, e.g.,
> >
> >         rm -f trace
> >         NCURSES_TRACE=0x220 gpsmon
> >
>
> I have recompiled ncurses with your latest patches and the --with-trace
> flag enabled.
> I have produced a traces as you requested, and fed it to tracemunch too.
> Please find the output attached.

The trace looks odd because the line with wprintw

        called {wprintw(window1,"Unknown device")

is indented by 16384 (which happens to be 2^14).  Each of those "+ "
levels is supposed to be corresponding to a call/return level.

In a quick check with one of ncurses test-programs (testcurs),
just in case I broke something.., I don't see any comparable oddness
in the trace around calls to wprintw.

So it seems that the odd trace might be in your build of ncurses.
(Or possibly since gpsmon does something with multiple threads,
it _could_ be calling some curses function without locking).

The level used by _tracef is in the data _nc_globals, i.e.,
_nc_globals.trace_level

The "Unknown device" message comes from gpsmon.c in refresh_statwin().
Unlike some other places in gpsmon.c, there's no report_lock() /
report_unlock() around the calls to this function, e.g., as
used in select_packet_monitor().  You might get better results with
the trace if the curses calls were consistently locked (whether
or not it seems "necessary").

--
Thomas E. Dickey <address@hidden>
https://invisible-island.net
ftp://ftp.invisible-island.net