esp-rs/espmonitor

Inline backtraces very hard to read

ivmarkov opened this issue · 3 comments

Perhaps it is just me, but NOT printing the decoded program counter information on a new line results in stacktraces which are basically human-unparseable.

I mean, spotting the stack frame before the one where the panic happened is almost mission impossible. Case in point:

thread 'blocking-2' panicked at 'attempt to subtract with overflow', /home/ivan/ldev/ruwm/ruwm/src/screen/shapes/battery.rs:169:23
abort() was called at PC 0x40124122 [_ZN11panic_abort18__rust_start_panic5abort17hc831f809d7a5881dE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/panic_abort/src/lib.rs:44] on core 0
Backtrace:0x40083916 [panic_abort:/home/ivan/ldev/ruwm/.embuild/espressif/esp-idf-release/v4.4/components/esp_system/panic.c:402]:0x3ffd35900x40088a05 [esp_system_abort:/home/ivan/ldev/ruwm/.embuild/espressif/esp-idf-release/v4.4/components/esp_system/esp_system.c:128]:0x3ffd35b0 0x4008f7fe [abort:/home/ivan/ldev/ruwm/.embuild/espressif/esp-idf-release/v4.4/components/newlib/abort.c:46]:0x3ffd35d0 0x40124122 [_ZN11panic_abort18__rust_start_panic5abort17hc831f809d7a5881dE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/panic_abort/src/lib.rs:44]:0x3ffd3640 0x40124116 [__rust_start_panic:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/panic_abort/src/lib.rs:39]:0x3ffd3660 0x40108199 [rust_panic:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/std/src/panicking.rs:654]:0x3ffd3680 0x40108186 [_ZN3std9panicking20rust_panic_with_hook17h7e41cb7f9ac6853dE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/std/src/panicking.rs:624]:0x3ffd3700 0x40103f83 [_ZN3std9panicking19begin_panic_handler28_$u7b$$u7b$closure$u7d$$u7d$17h5006254263c1cbafE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/std/src/panicking.rs:??]:0x3ffd3770 0x40103d99 [_ZN3std10sys_common9backtrace26__rust_end_short_backtrace17h05cd6519869595bbE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:139]:0x3ffd37a0 0x40107ec0 [rust_begin_unwind:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/std/src/panicking.rs:498]:0x3ffd37d0 0x40132583 [_ZN4core9panicking9panic_fmt17h4cdbd6d50cb773cdE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/core/src/panicking.rs:107]:0x3ffd3800 0x40132527 [_ZN4core9panicking5panic17h8638f101d46064a1E:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/core/src/panicking.rs:48]:0x3ffd3830 0x400db98d [_ZN4ruwm6screen6shapes7battery7Battery10draw_shape17h9026f99cbb5a6f72E:/home/ivan/ldev/ruwm/ruwm/src/screen/shapes/battery.rs:??]:0x3ffd3870 0x400eb9b9 [_ZN4ruwm6screen5pages7summary7Summary4draw17h53b8d08f928f8b31E:/home/ivan/ldev/ruwm/ruwm/src/screen/pages/summary.rs:54]:0x3ffd3940 0x400d6736 [_ZN4ruwm6screen27DrawEngine$LT$U$C$N$C$D$GT$4draw17h8dd767d7e23cbd18E:/home/ivan/ldev/ruwm/ruwm/src/screen.rs:209]:0x3ffd3980 0x400d6823 [_ZN4ruwm6screen27DrawEngine$LT$U$C$N$C$D$GT$3run28_$u7b$$u7b$closure$u7d$$u7d$28_$u7b$$u7b$closure$u7d$$u7d$17h8aedf44405b61bd8E:/home/ivan/ldev/ruwm/ruwm/src/screen.rs:190]:0x3ffd3a60 0x400d9575 [_ZN90_$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$9call_once17h9130dc4d6314c25cE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1694]:0x3ffd3b00 0x400d7527 [_ZN8blocking7unblock28_$u7b$$u7b$closure$u7d$$u7d$28_$u7b$$u7b$closure$u7d$$u7d$17hf4c0571251e45551E:/home/ivan/.cargo/registry/src/github.com-1ecc6299db9ec823/blocking-1.1.0/src/lib.rs:274]:0x3ffd3b20 0x400da2b5 [_ZN10async_task3raw24RawTask$LT$F$C$T$C$S$GT$3run17h97c2718a11a706e2E:/home/ivan/.cargo/registry/src/github.com-1ecc6299db9ec823/async-task-4.1.0/src/raw.rs:489]:0x3ffd3ba0 0x401b01ad [_ZN10async_task8runnable8Runnable3run17h928568e2245def82E:/home/ivan/.cargo/registry/src/github.com-1ecc6299db9ec823/async-task-4.1.0/src/runnable.rs:309]:0x3ffd3c50 0x400ebd3a [_ZN8blocking8Executor9main_loop28_$u7b$$u7b$closure$u7d$$u7d$17h3bd3eb18aa743d9aE:/home/ivan/.cargo/registry/src/github.com-1ecc6299db9ec823/blocking-1.1.0/src/lib.rs:186]:0x3ffd3c70 0x400ece40 [_ZN8blocking8Executor9grow_pool28_$u7b$$u7b$closure$u7d$$u7d$17h884cc7db93eede47E:/home/ivan/.cargo/registry/src/github.com-1ecc6299db9ec823/blocking-1.1.0/src/lib.rs:238]:0x3ffd3cd0 0x400ec93d [_ZN3std6thread7Builder15spawn_unchecked28_$u7b$$u7b$closure$u7d$$u7d$28_$u7b$$u7b$closure$u7d$$u7d$17ha8cf46191646e17eE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/std/src/thread/mod.rs:484]:0x3ffd3cf0 0x40121c1f [_ZN90_$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$9call_once17h7c215fd0622c2b92E:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1694]:0x3ffd3d20 0x40121c46 [_ZN90_$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$9call_once17hebef1896a4b359bfE:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1694]:0x3ffd3d40 0x4011c4b4 [_ZN3std3sys4unix6thread6Thread3new12thread_start17h37b3771fd6f72b91E:/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/std/src/sys/unix/thread.rs:106]:0x3ffd3d60 0x4013a41c [pthread_task_func:/home/ivan/ldev/ruwm/.embuild/espressif/esp-idf-release/v4.4/components/pthread/pthread.c:195]:0x3ffd3d80

Exercise: which is the stack frame before /home/ivan/ldev/ruwm/ruwm/src/screen/shapes/battery.rs:169:23?

I think the solution would be to follow what the ESP-IDF monitor does:

  • Process output on a line-by-line basis
  • If the current process line contains X program counters (where X > 0), grab them all
  • After the current line, print exactly X lines, where each line contains a PC counter in HEX + its decoding.
    I.e. something like:
Decoded PC [0x4XXXYYYY]: _ZN90_$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$9call_once17hebef1896a4b359bfE (/home/ivan/ldev/rust/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1694)

In fact, I would even first print the file + line number (as this is much more meaningful) and the function number as a second item.

Anybody home?

Anybody home?

No, as it turns out... I've been out of town for the past month and just got back last night. Will try to take a look soon.