Implement runtime stacktraces #1344

Thirumalai-Shaktivel · 2022-12-02T10:01:21Z

No description provided.

Thirumalai-Shaktivel · 2022-12-02T10:06:16Z

I added unwind_callback in the intrinsics.
Now, should I use this like as a decorator or function call in Python (to verify that we get the correct debug information.)
Can you please share what should I do next?
@certik

certik · 2022-12-02T16:03:01Z

Yes, I would check manually that the addresses that this returns are correct. I would also expose this so that the user can call it. Let's put it into ltypes, something like "ltypes.get_stacktrace_addresses()".

certik · 2022-12-03T08:49:21Z

Here is how to print the runtime stacktrace:

diff --git a/examples/expr2.py b/examples/expr2.py
index 2e66f1e58..f58eda174 100644
--- a/examples/expr2.py
+++ b/examples/expr2.py
@@ -1,6 +1,13 @@
+def g():
+    assert True
+
+def f():
+    g()
+
 def main0():
     x: i32
     x = (2+3)*5
+    f()
     print(x)
 
 main0()
diff --git a/src/libasr/codegen/asr_to_llvm.cpp b/src/libasr/codegen/asr_to_llvm.cpp
index e7144a025..de974de8d 100644
--- a/src/libasr/codegen/asr_to_llvm.cpp
+++ b/src/libasr/codegen/asr_to_llvm.cpp
@@ -4900,6 +4900,7 @@ public:
     }
 
     void visit_Assert(const ASR::Assert_t &x) {
+        call_print_stacktrace_addresses(context, *module, *builder, {});
         this->visit_expr_wrapper(x.m_test, true);
         create_if_else(tmp, []() {}, [=]() {
             if (x.m_msg) {

This prints:

$ lpython examples/expr2.py 
0 10008b8bb
1 10008b9d3
2 100067e53
3 100067e43
4 100067e6f
5 100067e33
6 100067e9f
25

Thirumalai-Shaktivel · 2022-12-03T13:58:36Z

src/libasr/runtime/lfortran_intrinsics.c

+        if (info->dlpi_phdr[i].p_type == PT_LOAD) {
+            ElfW(Addr) min_addr = info->dlpi_addr + info->dlpi_phdr[i].p_vaddr;
+            ElfW(Addr) max_addr = min_addr + info->dlpi_phdr[i].p_memsz;
+            printf("%lx\n", d->current_pc);


This prints 0, I think the value is not passed correctly.
@certik any idea why does this prints 0?

Thirumalai-Shaktivel · 2022-12-03T13:59:13Z

src/libasr/runtime/lfortran_intrinsics.c

+        if (dl_iterate_phdr(shared_lib_callback, &d) == 0) {
+            // printf("%d %lx %lx\n", i, d->pc[i], d->local_pc);
+            // printf("%lx\n", d->current_pc);


Here, it prints the correct value.

Thirumalai-Shaktivel · 2022-12-03T14:01:38Z

src/libasr/runtime/lfortran_intrinsics.c

+struct dl_phdr_info {
+    ElfW(Addr) dlpi_addr;
+    const char *dlpi_name;
+    const ElfW(Phdr) *dlpi_phdr;
+    ElfW(Half) dlpi_phnum;
+};
+
+extern int dl_iterate_phdr (int (*__callback) (struct dl_phdr_info *,
+    size_t, void *), void *__data);


I think the problem can be caused by this as well.
I added this because we get the following warning and error

home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1208:32: warning: ‘struct dl_phdr_info’ declared inside parameter list will not be visible outside of this definition or declaration 1208 | int shared_lib_callback(struct dl_phdr_info *info, | ^~~~~~~~~~~~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c: In function ‘shared_lib_callback’: /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1211:29: error: invalid use of undefined type ‘struct dl_phdr_info’ 1211 | for (int i = 0; i < info->dlpi_phnum; i++) { | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1212:17: error: invalid use of undefined type ‘struct dl_phdr_info’ 1212 | if (info->dlpi_phdr[i].p_type == PT_LOAD) { | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1213:39: error: invalid use of undefined type ‘struct dl_phdr_info’ 1213 | ElfW(Addr) min_addr = info->dlpi_addr + info->dlpi_phdr[i].p_vaddr; | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1213:57: error: invalid use of undefined type ‘struct dl_phdr_info’ 1213 | ElfW(Addr) min_addr = info->dlpi_addr + info->dlpi_phdr[i].p_vaddr; | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1214:50: error: invalid use of undefined type ‘struct dl_phdr_info’ 1214 | ElfW(Addr) max_addr = min_addr + info->dlpi_phdr[i].p_memsz; | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1220:51: error: invalid use of undefined type ‘struct dl_phdr_info’ 1220 | d->local_pc = d->current_pc - info->dlpi_addr; | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1221:37: error: invalid use of undefined type ‘struct dl_phdr_info’ 1221 | printf("%lx\n", info->dlpi_addr); | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1208:32: warning: ‘struct dl_phdr_info’ declared inside parameter list will not be visible outside of this definition or declaration 1208 | int shared_lib_callback(struct dl_phdr_info *info, | ^~~~~~~~~~~~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c: In function ‘shared_lib_callback’: /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1211:29: error: invalid use of undefined type ‘struct dl_phdr_info’ 1211 | for (int i = 0; i < info->dlpi_phnum; i++) { | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1212:17: error: invalid use of undefined type ‘struct dl_phdr_info’ 1212 | if (info->dlpi_phdr[i].p_type == PT_LOAD) { | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1213:39: error: invalid use of undefined type ‘struct dl_phdr_info’ 1213 | ElfW(Addr) min_addr = info->dlpi_addr + info->dlpi_phdr[i].p_vaddr; | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1213:57: error: invalid use of undefined type ‘struct dl_phdr_info’ 1213 | ElfW(Addr) min_addr = info->dlpi_addr + info->dlpi_phdr[i].p_vaddr; | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1214:50: error: invalid use of undefined type ‘struct dl_phdr_info’ 1214 | ElfW(Addr) max_addr = min_addr + info->dlpi_phdr[i].p_memsz; | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1220:51: error: invalid use of undefined type ‘struct dl_phdr_info’ 1220 | d->local_pc = d->current_pc - info->dlpi_addr; | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1221:37: error: invalid use of undefined type ‘struct dl_phdr_info’ 1221 | printf("%lx\n", info->dlpi_addr); | ^~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c: In function ‘print_stacktrace_addresses’: /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1235:13: warning: implicit declaration of function ‘dl_iterate_phdr’ [-Wimplicit-function-declaration] 1235 | if (dl_iterate_phdr(shared_lib_callback, &d) == 0) { | ^~~~~~~~~~~~~~~ /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c: In function ‘print_stacktrace_addresses’: /home/thirumalai/Open_Source/lpython/src/libasr/runtime/lfortran_intrinsics.c:1235:13: warning: implicit declaration of function ‘dl_iterate_phdr’ [-Wimplicit-function-declaration] 1235 | if (dl_iterate_phdr(shared_lib_callback, &d) == 0) { | ^~~~~~~~~~~~~~~ make[2]: *** [src/runtime/legacy/CMakeFiles/lpython_runtime_static.dir/build.make:76: src/runtime/legacy/CMakeFiles/lpython_runtime_static.dir/__/__/libasr/runtime/lfortran_intrinsics.c.o] Error 1 make[1]: *** [CMakeFiles/Makefile2:477: src/runtime/legacy/CMakeFiles/lpython_runtime_static.dir/all] Error 2 make[1]: *** Waiting for unfinished jobs.... make[2]: *** [src/runtime/legacy/CMakeFiles/lpython_runtime.dir/build.make:76: src/runtime/legacy/CMakeFiles/lpython_runtime.dir/__/__/libasr/runtime/lfortran_intrinsics.c.o] Error 1 make[1]: *** [CMakeFiles/Makefile2:451: src/runtime/legacy/CMakeFiles/lpython_runtime.dir/all] Error 2

certik · 2022-12-04T16:07:07Z

Not sure, we just need to debug it.

Thirumalai-Shaktivel · 2022-12-09T09:45:17Z

I was able to debug and fix the issue:
Here are the current output of print_stacktrace:

/home/thirumalai/Open_Source/lpython/src/bin/../runtime/liblpython_runtime.so
0 7fba4418ed0b: pc
7d0b: local_pc
/home/thirumalai/Open_Source/lpython/src/bin/../runtime/liblpython_runtime.so
1 7fba4418ef23: pc
7f23: local_pc

2 55bf57cca167: pc
1167: local_pc

3 55bf57cca155: pc
1155: local_pc

4 55bf57cca175: pc
1175: local_pc

5 55bf57cca145: pc
1145: local_pc

6 55bf57cca185: pc
1185: local_pc
/lib/x86_64-linux-gnu/libc.so.6
7 7fba43e90d8f: pc
29d8f: local_pc
/lib/x86_64-linux-gnu/libc.so.6
8 7fba43e90e3f: pc
29e3f: local_pc

9 55bf57cca074: pc
1074: local_pc

and llvm_dwarfdump:

Address            Line   Column File   ISA Discriminator Flags
------------------ ------ ------ ------ --- ------------- -------------
0x0000000000001140      0      0      1   0             0  is_stmt
0x0000000000001141     10      1      1   0             0  is_stmt prologue_end
0x0000000000001150      0      0      1   0             0  is_stmt
0x0000000000001151      2      5      1   0             0  is_stmt prologue_end
0x0000000000001160      0      0      1   0             0  is_stmt
0x0000000000001161      5      5      1   0             0  is_stmt prologue_end
0x0000000000001170      0      0      1   0             0  is_stmt
0x0000000000001171      8      5      1   0             0  is_stmt prologue_end
0x0000000000001180      0      0      1   0             0  is_stmt
0x0000000000001181      1      1      1   0             0  is_stmt prologue_end
0x000000000000118a      1      1      1   0             0  is_stmt end_sequence

I think we are getting the almost near address.
file:

     1	def f():
     2	    g()
     3	
     4	def g():
     5	    assert True
     6	
     7	def main0():
     8	    f()
     9	
    10	main0()
    11	
    12	# Not implemented yet in LPython:
    13	#if __name__ == "__main__":
    14	#    main()

Thirumalai-Shaktivel · 2022-12-09T09:46:27Z

Now, I will try to map the address and report back.

Thirumalai-Shaktivel · 2022-12-09T11:06:11Z

@certik how does dwarf_convert.py work?
I ask this because the lines.dat doesn't seem to be correct:
lines.dat: size

A: 144

$ cat lines.txt
1
examples/expr2.py
6

Are the above contents correct? is this the expected output from dwarf_convert?

Thirumalai-Shaktivel · 2022-12-09T11:18:46Z

lpython/src/bin/dwarf_convert.py

Lines 160 to 162 in 08b04b0

    
           with open(sys.argv[3], "wb") as f: 
        
               for addr, line, fileid in asr.addresses: 
        
                   f.write(pack("3Q", addr, line, fileid))

From above code, the contents seem to be correct print (addr, line)

How do I unpack this correctly?

Thirumalai-Shaktivel · 2022-12-09T11:20:45Z

Why convert to lines.dat, we could have written to text file, right?

Thirumalai-Shaktivel · 2022-12-09T15:22:51Z

Here is the current ouput:

examples/expr2.py: 140371440169592
	#    main()

examples/expr2.py: 8
	    f()

examples/expr2.py: 5
	    assert True

examples/expr2.py: 1
	def f():

examples/expr2.py: 2
	    g()

examples/expr2.py: 140371440169592
	#    main()

There are some bugs, I will debug it tomorrow.

certik · 2022-12-09T16:58:29Z

Excellent progress!

I'll have time to meet next week if you need my help. This is good.

Thirumalai-Shaktivel · 2022-12-10T06:38:56Z

This PR is ready for review!
Here is the stack trace output:

There are two things to do next:

Last two line from the above image is not required or doesn't show the correct information.

There is some file information that we need to handle. Here is the output of the binary_filename array:

 0: /home/thirumalai/Open_Source/lpython/src/bin/../runtime/liblpython_runtime.so
 1: /home/thirumalai/Open_Source/lpython/src/bin/../runtime/liblpython_runtime.so
 2: examples/expr2.py
 3: examples/expr2.py
 4: examples/expr2.py
 5: examples/expr2.py
 6: examples/expr2.py
 7: /lib/x86_64-linux-gnu/libc.so.6
 8: /lib/x86_64-linux-gnu/libc.so.6
 9: examples/expr2.py

Thirumalai-Shaktivel · 2022-12-10T06:49:12Z

Reproduce the output using:

$ lpython examples/expr2.py -g --debug-with-line-column -o a.out
$ llvm-dwarfdump --debug-line a.out > a.txt
$ (cd src/bin; ./dwarf_convert.py ../../a.txt ../../lines.txt ../../lines.dat)
$ ./src/bin/dat_convert.py lines.dat
$ ./a.out
  File "examples/expr2.py", line 5
    assert True
  File "examples/expr2.py", line 2
    g()
  File "examples/expr2.py", line 8
    f()
  File "examples/expr2.py", line 10
    main0()
  File "examples/expr2.py", line 1
    def f():
  File "examples/expr2.py", line 10
    main0()

certik · 2022-12-13T04:46:38Z

Awesome, very good!

I think this is pretty much it, now we just need to polish this.

certik · 2022-12-13T16:56:38Z

src/libasr/codegen/asr_to_llvm.cpp

+        llvm::Value *fmt_ptr = builder->CreateGlobalStringPtr(infile);
+        call_print_stacktrace_addresses(context, *module, *builder, {fmt_ptr});


These two lines should be moved below into the create_if_else branch.

certik · 2022-12-13T16:57:30Z

src/libasr/runtime/lfortran_intrinsics.c

@@ -1165,3 +1171,177 @@ LFORTRAN_API void _lpython_close(int64_t fd)
        exit(1);
    }
 }
+


Wrap this into #ifdef HAVE_LFORTRAN_UNWIND

certik · 2022-12-13T16:57:43Z

src/libasr/runtime/lfortran_intrinsics.h

@@ -6,6 +6,9 @@
 #include <inttypes.h>
 #include <stdbool.h>

+#include <unwind.h>


Move into .c and wrap with #ifdef HAVE_LFORTRAN_UNWIND

certik · 2022-12-13T16:58:00Z

src/libasr/runtime/lfortran_intrinsics.h

@@ -6,6 +6,9 @@
 #include <inttypes.h>
 #include <stdbool.h>

+#include <unwind.h>
+#include <ctype.h>


certik · 2022-12-13T16:58:17Z

src/libasr/runtime/lfortran_intrinsics.h

@@ -18,6 +21,33 @@ struct _lfortran_complex_64 {
    double re, im;
 };

+// Runtime Stacktrace
+#define LCOMPILERS_MAX_STACKTRACE_LENGTH 200
+char *binary_filename;


Move into .c

certik · 2022-12-13T16:58:32Z

src/libasr/runtime/lfortran_intrinsics.h

+// Styles and Colors
+#define DIM "\033[2m"
+#define BOLD "\033[1m"
+#define S_RESET "\033[0m"
+#define MAGENTA "\033[35m"
+#define C_RESET "\033[39m"


…TRACE ifdef block

Thirumalai-Shaktivel · 2023-01-12T15:32:51Z

Finally, I was able to pass all the tests.
@certik, you can now do the final review.

certik

I think this looks good enough to merge. Rebase or squash the history before merging.

Thirumalai-Shaktivel · 2023-01-13T03:48:37Z

Thanks for the approval and guidance

Thirumalai-Shaktivel force-pushed the runtime_stacktrace branch 3 times, most recently from 43580a1 to d3df449 Compare December 2, 2022 10:04

Thirumalai-Shaktivel commented Dec 3, 2022

View reviewed changes

Thirumalai-Shaktivel force-pushed the runtime_stacktrace branch 2 times, most recently from 4784db2 to 56ca046 Compare December 9, 2022 10:58

Thirumalai-Shaktivel force-pushed the runtime_stacktrace branch from 56ca046 to e4708ff Compare December 9, 2022 11:09

Thirumalai-Shaktivel force-pushed the runtime_stacktrace branch from e4708ff to c7b8953 Compare December 9, 2022 15:20

certik reviewed Dec 13, 2022

View reviewed changes

Thirumalai-Shaktivel force-pushed the runtime_stacktrace branch 3 times, most recently from 224291a to 066ea44 Compare January 12, 2023 07:40

Thirumalai-Shaktivel added 7 commits January 12, 2023 14:47

Use Libasr as a target_include_directories for lpython_runtime

4dc7c2d

Increase the malloc size for the command

b8f648b

Enclose the runtime stacktrace handling within the HAVE_RUNTIME_STACK…

58f133a

…TRACE ifdef block

Enable Runtime Stacktrace in the CI

59df7fd

Generate the runtime_stacktrace related files during the compile-time

3708557

Add a warning to use an option to print correct location info

b9d0738

Add a test and update refs.

f00fe46

Thirumalai-Shaktivel force-pushed the runtime_stacktrace branch 7 times, most recently from 72909ad to 264bbdb Compare January 12, 2023 14:47

[MacOS] Ignore other file information except the source binary

70323bb

Thirumalai-Shaktivel force-pushed the runtime_stacktrace branch from 264bbdb to 70323bb Compare January 12, 2023 15:11

Thirumalai-Shaktivel added the ready for review PRs that are ready for review label Jan 12, 2023

Thirumalai-Shaktivel requested a review from certik January 12, 2023 15:33

Thirumalai-Shaktivel marked this pull request as ready for review January 12, 2023 15:33

certik approved these changes Jan 12, 2023

View reviewed changes

Thirumalai-Shaktivel changed the title ~~Create runtime stacktraces~~ Implement runtime stacktraces Jan 13, 2023

Thirumalai-Shaktivel merged commit a5aa754 into lcompilers:main Jan 13, 2023

Thirumalai-Shaktivel deleted the runtime_stacktrace branch January 13, 2023 03:47

Thirumalai-Shaktivel mentioned this pull request Feb 20, 2023

Sync libasr with LFortran #1535

Merged

Thirumalai-Shaktivel mentioned this pull request Sep 28, 2023

Create runtime stacktraces #772

Open

		llvm::Value *fmt_ptr = builder->CreateGlobalStringPtr(infile);
		call_print_stacktrace_addresses(context, module, builder, {fmt_ptr});

Implement runtime stacktraces #1344

Implement runtime stacktraces #1344

Uh oh!

Conversation

Thirumalai-Shaktivel commented Dec 2, 2022

Uh oh!

Thirumalai-Shaktivel commented Dec 2, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

certik commented Dec 2, 2022

Uh oh!

certik commented Dec 3, 2022

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Thirumalai-Shaktivel Dec 3, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

certik commented Dec 4, 2022

Uh oh!

Thirumalai-Shaktivel commented Dec 9, 2022

Uh oh!

Thirumalai-Shaktivel commented Dec 9, 2022

Uh oh!

Thirumalai-Shaktivel commented Dec 9, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Thirumalai-Shaktivel commented Dec 9, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Thirumalai-Shaktivel commented Dec 9, 2022

Uh oh!

Thirumalai-Shaktivel commented Dec 9, 2022

Uh oh!

certik commented Dec 9, 2022

Uh oh!

Thirumalai-Shaktivel commented Dec 10, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Thirumalai-Shaktivel commented Dec 10, 2022 • edited by certik Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

certik commented Dec 13, 2022

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Thirumalai-Shaktivel commented Jan 12, 2023

Uh oh!

certik left a comment

Choose a reason for hiding this comment

Uh oh!

Thirumalai-Shaktivel commented Jan 13, 2023

Uh oh!

Uh oh!

Thirumalai-Shaktivel commented Dec 2, 2022 •

edited

Loading

Thirumalai-Shaktivel Dec 3, 2022 •

edited

Loading

Thirumalai-Shaktivel commented Dec 9, 2022 •

edited

Loading

Thirumalai-Shaktivel commented Dec 9, 2022 •

edited

Loading

Thirumalai-Shaktivel commented Dec 10, 2022 •

edited

Loading

Thirumalai-Shaktivel commented Dec 10, 2022 •

edited by certik

Loading