ms5611 test shows a stack trace

[LorenzMeier]

When running the ms5611 test in px4dev_new_driver, it shows a stack trace in an otherwise unloaded system:

nsh> ms5611 test
ms5611: Assertion failed at file:/Users/user/src/Firmware/nuttx/sched/work_cancel.c line: 107 task: ms5611
sp:         10005d80
stack base: 10005e78
stack size: 000007fc
10005d80: 10005e78 10005d80 1000567c 08005f8d 0000006b 0000006b 08050b05 10004950
10005da0: 0000000b 08006097 100047b0 08026fb9 00000000 0804060f 0802717f 08026fa1
10005dc0: 10004740 08026fb9 10004740 08025e9b 10006290 0802717f 0802e971 08025e75
10005de0: 080270c9 100044c0 00002002 08025e9b 08025e75 08026937 0804c15c 00002002
10005e00: 0000000a 00000000 00000000 0802e971 079ebfdf 00000003 00000000 00000000
10005e20: 00000000 08026937 4472cf5c 43b1e32c 4207d70a ffffffff 079ebfdf 00000000
10005e40: 00000000 00000000 00000000 00000000 10003b50 00000000 00000000 00000000
10005e60: 00000000 08027593 00000000 0800b557 00000000 00000000 ffffffff 00000000
single read
ms5611: pressure:    971
ms5611: altitude:    355
ms5611: temperature: 33
ms5611: time:        127844319

[LorenzMeier]

Interestingly vanished in commit 56e66a8

[px4dev]

This is usually a consequence of calling work_cancel() on a work item that has never been scheduled, and/or was allocated but not zero-filled, or has been overwritten by something.

[px4dev]

There is definitely an issue with start/stop on work items in these drivers that needs to be addressed.

[px4dev]

There seems to be a problem with work_cancel once more than one work item is present on the list. Needs more debugging.

[LorenzMeier]

This has been resolved.

[LorenzMeier]

@julianoes This seems to have surfaced again in the driver calibration. @px4dev A quick look would be appreciated.

[LorenzMeier]

Julian digged this up via GDB:

Program received signal SIGINT, Interrupt.
work_process (wqueue=0x20003538) at wqueue/work_thread.c:139
139       elapsed = clock_systimer() - work->qtime;
(gdb) continue
Continuing.
^C
Program received signal SIGINT, Interrupt.
work_process (wqueue=0x20003538) at wqueue/work_thread.c:139
139       elapsed = clock_systimer() - work->qtime;
(gdb) bt   
#0  work_process (wqueue=0x20003538) at wqueue/work_thread.c:139
#1  0x08083120 in work_hpthread (argc=<optimized out>, argv=<optimized out>)
    at wqueue/work_thread.c:257
#2  0x0807e9c8 in task_start () at task_start.c:138
#3  0x00000000 in ?? ()
(gdb) bt full
#0  work_process (wqueue=0x20003538) at wqueue/work_thread.c:139
        work = 0x1000f160
        worker = <optimized out>
        flags = <optimized out>
        arg = <optimized out>
        elapsed = <optimized out>
        remaining = <optimized out>
        next = <optimized out>
#1  0x08083120 in work_hpthread (argc=<optimized out>, argv=<optimized out>)
    at wqueue/work_thread.c:257
No locals.
#2  0x0807e9c8 in task_start () at task_start.c:138
        tcb = <optimized out>
        exitcode = <optimized out>
        argc = <optimized out>
#3  0x00000000 in ?? ()
No symbol table info available.
(gdb) info frame
Stack level 0, frame at 0x10001928:
 pc = 0x8083082 in work_process (wqueue/work_thread.c:139); saved pc 0x8083120
 called by frame at 0x10001930
 source language c.
 Arglist at 0x10001900, args: wqueue=0x20003538
 Locals at 0x10001900, Previous frame's sp is 0x10001928
 Saved registers:
  r4 at 0x10001908, r5 at 0x1000190c, r6 at 0x10001910, r7 at 0x10001914,
  r8 at 0x10001918, r9 at 0x1000191c, r11 at 0x10001920, lr at 0x10001924

[LorenzMeier]

Using a workaround right now in mag calibration, but not resolved yet.

[LorenzMeier]

With the new buffer structure finally fixed. Yay!