c3c icon indicating copy to clipboard operation
c3c copied to clipboard

Macros and the call stack

Open cbuttner opened this issue 1 year ago • 11 comments

Macros add serious complications to debugging when it comes to the call stack. When the instruction pointer points to a source code location inside a macro, the location of the macro invocation and the actual function that should be on top of the stack is completely lost.

From a users perspective, the best solution would be if every macro was wrapped in a function call if some debug compilation flag is set.

If that's not possible or too complicated, I'd actually prefer to have all source code locations inside a macro collapse to the invocation location. This would mimic C macros.

cbuttner avatar Apr 17 '24 12:04 cbuttner

Can you give an example and explain what you'd like to see and what you see instead?

lerno avatar Apr 17 '24 14:04 lerno

The simplest example I can give is

fn void main() {
  foo();
}

fn void foo() {
  bar();
}

macro bar() {
  unreachable();
}

Which gives the call stack

fn default_panic
fn panicf
fn foo <- At builtin.c3:145 inside macro unreachable, where panicf is called
fn main

Note that in practice I don't know where I am inside foo, which is the problem. What I expect (C macro style):

fn default_panic
fn panicf
fn foo <- At where bar() is invoked
fn main

Or if the macros were wrapped into function calls:

fn default_panic
fn panicf
fn unreachable <- Where panicf is called
fn bar <- Where unreachable() is invoked
fn foo <- Where bar() is invoked
fn main

cbuttner avatar Apr 17 '24 14:04 cbuttner

I think this could be improved with better debug codegen. I'll have a look.

lerno avatar Apr 17 '24 22:04 lerno

I've done an update to the dev branch to improve this, see if you like it.

lerno avatar Apr 18 '24 06:04 lerno

Yes, that's a lot better! Now it's possible to step in and out of macros too. I was unaware this could be done with debug info. This is very helpful.

Although stepping over a trailing body macro in the debugger will counter-intuitively step over the whole block, and when you're stepping inside a trailing macro body, there will be two functions on the call stack (for example, one at @pool and one inside the @pool block). This is not as big a deal though.

Also the stackdump for my example looks like this (on linux), maybe you can reproduce and figure out what's going on here:

ERROR: 'Unreachable statement reached.'
  in std.core.builtin.default_panic (/usr/lib/c3c/lib/std/core/builtin.c3:104)
  in std.core.builtin.panicf (source unavailable)
  in ??? (source unavailable)
  in test_c3.main (main.c3:31)
  in main (source unavailable)

cbuttner avatar Apr 18 '24 13:04 cbuttner

Hmmm.. so that's the stackdump for the example above? What happened before?

lerno avatar Apr 18 '24 14:04 lerno

This is what I see on MacOS with your code:

ERROR: 'Unreachable statement reached.'
  in std.core.builtin.panicf (/Users/lerno/Projects/c3c/lib/std/core/builtin.c3:129) [test]
  in test.foo (/Users/lerno/Projects/c3c/resources/testfragments/debugstuff.c3:8) [test]
  in test.main (/Users/lerno/Projects/c3c/resources/testfragments/debugstuff.c3:4) [test]
  in main (/Users/lerno/Projects/c3c/resources/testfragments/debugstuff.c3:3) [test]
  in start (source unavailable) [/usr/lib/dyld]
Program interrupted by signal 4.

lerno avatar Apr 20 '24 00:04 lerno

So this is what I get before 480f0f8 (at 2bfc7258):

ERROR: 'Unreachable statement reached.'
  in std.core.builtin.default_panic (/home/christian/Github/c3c/lib/std/core/builtin.c3:104) [./build/test]
  in std.core.builtin.panicf (/home/christian/Github/c3c/lib/std/core/builtin.c3:134) [./build/test]
  in test.foo (/home/christian/Github/c3c/lib/std/core/builtin.c3:145) [./build/test]
  in test.main (/tmp/test/src/main.c3:6) [./build/test]
  in main (/home/christian/Github/c3c/lib/std/core/private/main_stub.c3:18) [./build/test]
  in __libc_init_first (source unavailable) [/usr/lib/libc.so.6]
  in __libc_start_main (source unavailable) [/usr/lib/libc.so.6]
  in _start (source unavailable) [./build/test]
Program interrupted by signal 4.

After (at dev head, nothing else changed):

ERROR: 'Unreachable statement reached.'
  in std.core.builtin.default_panic (/home/christian/Github/c3c/lib/std/core/builtin.c3:104) [./build/test]
  in std.core.builtin.panicf (source unavailable) [./build/test]
  in ??? (source unavailable) [./build/test]
  in test.main (/tmp/test/src/main.c3:6) [./build/test]
  in main (source unavailable) [./build/test]
  in __libc_init_first (source unavailable) [/usr/lib/libc.so.6]
  in __libc_start_main (source unavailable) [/usr/lib/libc.so.6]
  in _start (source unavailable) [./build/test]
Program interrupted by signal 4.

cbuttner avatar Apr 25 '24 09:04 cbuttner

@cbuttner If you grab a C stack trace with inline code, how does it look?

lerno avatar Apr 26 '24 15:04 lerno

Can you check if you still get this problem with the latest?

lerno avatar May 19 '24 07:05 lerno

Yes, the Linux stack trace code seems to have a problem. In general there is no problem with C code and common stack trace implementations.

I can compare against what libunwind gives, which seems to be better.

// From libunwind:
0x95821392465051: (std.core.builtin.print_backtrace+0x1b)
0x95821392467432: (std.core.builtin.default_panic+0x38)
0x95821392464970: (std.core.builtin.panicf+0x28a)
0x95821392442493: (test.foo+0x6d)
0x95821392442377: (test.main+0x9)
0x95821392442530: (main+0x22)
0x133368082361480: -- error: unable to obtain symbol name for this frame
0x133368082361676: (__libc_start_main+0x8c)
0x95821392442149: (_start+0x25)

// From C3:
ERROR: 'Unreachable statement reached.'
  in std.core.builtin.default_panic (/home/christian/Github/c3c/lib/std/core/builtin.c3:147) [./build/test]
  in std.core.builtin.panicf (/home/christian/Github/c3c/lib/std/core/builtin.c3:177) [./build/test]
  in ??? (source unavailable) [./build/test]
  in test.main (/tmp/test/src/main.c3:18) [./build/test]
  in main (source unavailable) [./build/test]
  in __libc_init_first (source unavailable) [/usr/lib/libc.so.6]
  in __libc_start_main (source unavailable) [/usr/lib/libc.so.6]
  in _start (source unavailable) [./build/test]

cbuttner avatar May 20 '24 10:05 cbuttner

Does the latest show a better stacktrace now?

lerno avatar Jun 06 '24 22:06 lerno

No, still the same.

cbuttner avatar Jun 07 '24 12:06 cbuttner

If you're willing to experiment with this, the backtrace code is all in lib/std/os/linux/linux.c3

What you could do is to output the data sent to addr2line and see where it seems to fail. For example, you can try to leave out "-i" and see what happens.

lerno avatar Jun 07 '24 22:06 lerno

Please try it now.

lerno avatar Jun 08 '24 11:06 lerno

Looks very good now.

ERROR: 'Unreachable statement reached.'
  in std.core.builtin.default_panic (/home/christian/Github/c3c/lib/std/core/builtin.c3:105) [./build/test]
  in std.core.builtin.panicf (/home/christian/Github/c3c/lib/std/core/builtin.c3:135) [./build/test]
  in unreachable (/home/christian/Github/c3c/lib/std/core/builtin.c3:146) [./build/test] [inline]
  in bar (/tmp/test/src/main.c3:15) [./build/test] [inline]
  in test.foo (/tmp/test/src/main.c3:11) [./build/test]
  in test.main (/tmp/test/src/main.c3:7) [./build/test]
  in @main_to_void_main (/home/christian/Github/c3c/lib/std/core/private/main_stub.c3:18) [./build/test] [inline]
  in main (/tmp/test/src/main.c3:6) [./build/test]
  in __libc_init_first (source unavailable) [/usr/lib/libc.so.6]
  in __libc_start_main (source unavailable) [/usr/lib/libc.so.6]
  in _start (source unavailable) [./build/test]

I think we can close this then.

cbuttner avatar Jun 08 '24 12:06 cbuttner