Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RISC-V: Support PLT hooking to trace library functions #1853

Closed
namhyung opened this issue Dec 6, 2023 · 33 comments
Closed

RISC-V: Support PLT hooking to trace library functions #1853

namhyung opened this issue Dec 6, 2023 · 33 comments

Comments

@namhyung
Copy link
Owner

namhyung commented Dec 6, 2023

Now we have the basic RISC-V (64-bit) support but it still lacks the library call tracing. I'd like to have it before the new release.

This work is a part of RISC-V support (#1503).

@namhyung
Copy link
Owner Author

namhyung commented Dec 6, 2023

Please check review/riscv-libcall-v1.

I only tested it on qemu but it works well for me.

$ uftrace -a --force uname -a
Linux ubuntu 6.2.0-37-generic #38.1-Ubuntu SMP Wed Nov 15 03:03:57 UTC 2023 riscv64 riscv64 riscv64 GNU/Linux
# DURATION     TID     FUNCTION
 456.100 us [  4496] | strrchr("uname", '/') = "NULL";
   4.253 ms [  4496] | setlocale(LC_ALL, "") = "C.UTF-8";
   9.500 us [  4496] | bindtextdomain("coreutils", "/usr/share/locale");
   4.700 us [  4496] | textdomain("coreutils");
   2.500 us [  4496] | __cxa_atexit();
   8.800 us [  4496] | getopt_long(2, 0x3ff8fe68c8, "asnrvmpio") = 97;
   2.800 us [  4496] | getopt_long(2, 0x3ff8fe68c8, "asnrvmpio") = -1;
  12.700 us [  4496] | uname();
 113.100 us [  4496] | fputs_unlocked();
   2.300 us [  4496] | __overflow();
   3.400 us [  4496] | fputs_unlocked();
   1.000 us [  4496] | __overflow();
   2.200 us [  4496] | fputs_unlocked();
   1.000 us [  4496] | __overflow();
   1.600 us [  4496] | fputs_unlocked();
   1.100 us [  4496] | __overflow();
   1.300 us [  4496] | fputs_unlocked();
  25.600 us [  4496] | uname();
   5.000 us [  4496] | strcmp("riscv64", "i686") = 9;
   1.100 us [  4496] | __overflow();
   1.400 us [  4496] | fputs_unlocked();
   4.200 us [  4496] | uname();
   1.100 us [  4496] | __overflow();
   1.300 us [  4496] | fputs_unlocked();
   1.000 us [  4496] | __overflow();
   1.400 us [  4496] | fputs_unlocked();
  76.600 us [  4496] | __overflow();
   1.600 us [  4496] | __fpending();
   2.600 us [  4496] | fileno(&_IO_2_1_stdout_) = 1;
   1.200 us [  4496] | __freading();
   0.900 us [  4496] | __freading();
   3.800 us [  4496] | fflush(&_IO_2_1_stdout_) = 0;
 350.600 us [  4496] | fclose(&_IO_2_1_stdout_) = 0;
   1.100 us [  4496] | __fpending();
   1.900 us [  4496] | fileno(&_IO_2_1_stderr_) = 2;
   1.000 us [  4496] | __freading();
   1.000 us [  4496] | __freading();
   1.700 us [  4496] | fflush(&_IO_2_1_stderr_) = 0;
   5.200 us [  4496] | fclose(&_IO_2_1_stderr_) = 0;

@namhyung
Copy link
Owner Author

namhyung commented Dec 6, 2023

My test result is like below:

$ make runtest -j2
  TEST     test_run
Start 286 tests with 2 worker

Compiler                  gcc                          
Runtime test case         pg             finstrument-fu
------------------------: O0 O1 O2 O3 Os O0 O1 O2 O3 Os
001 basic               : OK OK OK OK OK OK OK OK OK OK
002 argument            : OK OK OK OK OK OK OK OK OK OK
003 thread              : OK OK OK OK OK OK OK OK OK OK
004 filter_F            : OK OK OK OK OK OK OK OK OK OK
005 filter_N            : OK OK OK OK OK OK OK OK OK OK
006 filter_FN           : OK OK OK OK OK OK OK OK OK OK
007 library             : OK OK OK OK OK OK OK OK OK OK
008 daemon              : OK OK OK OK OK OK OK OK OK OK
009 fork                : OK OK OK OK OK OK OK OK OK OK
010 forkexec            : OK OK OK OK OK OK OK OK OK OK
...


runtime test stats
====================
total  2860  Tests executed (success: 62.83%)
  OK:  1741  Test succeeded
  OK:    56  Test succeeded (with some fixup)
  NG:   214  Different test result
  NZ:     4  Non-zero return value
  SG:     5  Abnormal exit by signal
  TM:     0  Test ran too long
  BI:    10  Build failed
  LA:     0  Unsupported Language
  SK:   830  Skipped

@gichoel
Copy link
Contributor

gichoel commented Dec 6, 2023

The following results were obtained from VisionFive2 RISC-V board.

$ ./uftrace --libmcount-path=. -a --force uname -a
Linux starfive 5.15.0-starfive #1 SMP Wed Aug 23 11:18:20 CST 2023 riscv64 GNU/Linux
# DURATION     TID     FUNCTION
 246.006 us [  2178] | strrchr("uname", '/') = "NULL";
  18.000 us [  2178] | setlocale(LC_ALL, "") = "C";
   5.000 us [  2178] | bindtextdomain("coreutils", "/usr/share/locale");
   2.750 us [  2178] | textdomain("coreutils");
   2.000 us [  2178] | __cxa_atexit();
   4.251 us [  2178] | getopt_long(2, 0x3ffa999198, "asnrvmpio") = 97;
   4.250 us [  2178] | uname();
   8.250 us [  2178] | fputs_unlocked();
   2.000 us [  2178] | __overflow();
   2.500 us [  2178] | __fpending();
   2.250 us [  2178] | fileno(&_IO_2_1_stdout_) = 1;
   2.251 us [  2178] | __freading();
   2.500 us [  2178] | fflush(&_IO_2_1_stdout_) = 0;
   4.500 us [  2178] | fclose(&_IO_2_1_stdout_) = 0;

@honggyukim
Copy link
Collaborator

Thanks for working on this! But I see many failures in a RISC-V board and one of the failure is as follows.

$ gcc -pg -o t-thread tests/s-thread.c -pthread
$ uftrace t-thread 
plthook: /home/user/work/uftrace/git/uftrace/libmcount/plthook.c:1014:__plthook_exit
 ERROR: <2> invalid dynsym idx: -269488145
# DURATION     TID     FUNCTION
            [ 80911] | main() {
 146.002 us [ 80911] |   pthread_create();

uftrace stopped tracing with remaining functions
================================================
task: 80911
[0] main

@honggyukim
Copy link
Collaborator

Here are the full failures except for argument tests.

$ cat failed-tests.txt | grep -v arg
Compiler                  gcc                            clang                        
Runtime test case         pg             finstrument-fu  pg             finstrument-fu
------------------------: O0 O1 O2 O3 Os O0 O1 O2 O3 Os  O0 O1 O2 O3 Os O0 O1 O2 O3 Os
003 thread              : NZ SG NZ NZ NZ NG NG NG NG NG  NZ NZ NZ NZ NZ NG NG NG NG NG
007 library             : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
008 daemon              : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG OK OK OK OK OK
009 fork                : OK OK OK OK OK NG NG NG NG NG  OK OK OK OK OK NG NG NG NG NG
011 vforkexec           : OK OK OK OK OK NG NG NG NG NG  OK OK OK OK OK NG NG NG NG NG
012 demangle            : NZ NZ NZ NZ NZ OK OK OK OK OK  NZ NZ NZ NZ NZ OK OK OK OK OK
013 signal              : NZ NZ NZ NZ NZ OK OK OK OK OK  NZ NZ NZ NZ NZ OK OK OK OK OK
014 ucontext            : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
015 longjmp             : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
016 alloca              : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
031 filter_demangle1    : OK OK OK OK OK SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
032 filter_demangle2    : NG NG NG NG NG SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
033 filter_demangle3    : NZ NZ NZ NZ NZ SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
034 filter_demangle4    : OK OK OK OK OK SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
035 filter_demangle5    : NG NG NG NG NG SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
036 replay_filter_N     : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
037 trace_onoff         : NZ NZ NZ NZ NZ SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
038 trace_disable       : NZ NZ NZ NZ NZ SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
039 trace_onoff_F       : OK OK OK OK OK SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
040 replay_onoff        : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
041 replay_onoff_N      : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
042 live_disable        : NG NG NG NG NG SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
043 full_demangle       : NZ NZ NZ NZ NZ SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
046 report_task         : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG OK OK OK OK OK
047 signal2             : NZ NZ NZ NZ NZ OK OK OK OK OK  NZ NZ NZ NZ NZ OK OK OK OK OK
048 malloc_impl         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
049 column_view         : NZ NZ SG NZ NZ NG NG NG NG NG  NZ NZ NZ NZ NZ NG NG NG NG NG
051 return              : OK OK OK OK OK NZ NZ NZ NZ NZ  OK OK OK OK OK NZ OK OK OK OK
052 nested_func         : NZ OK OK OK OK NG OK OK OK OK  SK SK SK SK SK SK SK SK SK SK
063 retval              : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
066 no_demangle         : OK OK OK OK OK SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG
071 graph_depth         : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
074 lib_trigger         : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
077 lib_replay_T        : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
091 replay_tid          : OK OK OK OK OK NG NG NG NG NG  OK OK OK OK OK NG NG NG NG NG
092 report_tid          : OK OK OK OK OK OK OK NG OK OK  OK OK OK OK OK OK OK OK OK OK
094 report_depth        : OK OK OK OK OK OK OK OK NG OK  OK OK OK NG OK OK OK OK OK OK
095 graph_tid           : OK OK OK OK OK NG NG NG NG NG  OK OK OK OK OK NG NG NG NG NG
098 dump_tid            : OK OK OK OK OK NG NG NG NG NG  OK OK OK OK OK NG NG NG NG NG
102 dump_flamegraph     : OK OK OK NG OK OK OK OK OK OK  OK OK OK OK OK OK OK OK OK OK
109 replay_time_A       : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
112 replay_skip         : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
118 thread_tsd          : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
119 malloc_hook         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
120 malloc_tsd          : NG NG NG NG NG NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
121 malloc_fork         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
124 exception           : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
130 thread_exec         : NZ NZ NZ NZ NZ OK OK OK OK OK  NZ NZ NZ NZ NZ OK OK OK OK OK
131 lib_dlopen          : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
140 dynamic_xray        : BI BI BI BI BI BI BI BI BI BI  BI BI BI BI BI BI BI BI BI BI
144 longjmp2            : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
145 longjmp3            : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
154 keep_pid            : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG OK OK OK OK OK
158 report_diff_policy1 : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
159 report_diff_policy2 : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
160 report_diff_policy3 : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
162 pltbind_now_pie     : OK OK OK OK OK OK OK OK OK OK  BI BI BI BI BI BI BI BI BI BI
163 event_sched         : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
164 report_sched        : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
165 graph_sched         : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
166 dump_sched          : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
167 recv_sched          : NG NG NG NG NG NG NG NG NG NG  NG NG NZ NG NG NG NG NG NG NG
168 lib_nested          : NG NG NG NG NG NG NG NG NG NG  OK OK OK OK OK OK OK OK OK OK
172 trigger_filter      : NZ NZ NZ NZ NZ SG SG SG SG SG  SG TM SG SG SG SG SG SG SG SG
177 report_diff_policy4 : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
182 thread_exit         : NZ NZ SG NZ NZ NG NG NG NG NG  NZ NZ SG NZ SG NG NG NG NG NG
185 exception2          : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NG NG NG NG NG
186 exception3          : NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
189 replay_field2       : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
191 posix_spawn         : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
192 lib_name            : NG NG NG NG NG NG NG NG NG NG  OK OK OK OK OK OK OK OK OK OK
193 read_pmu_cycle      : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
194 read_pmu_cache      : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
195 read_pmu_branch     : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
196 chrome_taskname     : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
200 lib_dlopen2         : OK OK OK OK OK NG NG NG NG NG  OK OK OK OK OK NG NG NG NG NG
208 watch_cpu           : NG NG NG NG NG SG SG SG SG SG  NG NG NG NG NG SG SG SG SG SG
214 signal_trigger      : NZ NZ NZ NZ NZ OK OK OK OK OK  NZ NZ NZ NZ NZ OK OK OK OK OK
215 no_libcall_replay   : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG OK OK OK OK OK
216 no_libcall_report   : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG OK OK OK OK OK
217 no_libcall_dump     : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG OK OK OK OK OK
218 no_libcall_graph    : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG OK OK OK OK OK
219 no_libcall_script   : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG OK OK OK OK OK
221 taskname_time       : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
226 default_opts        : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
227 read_pmu_cycle2     : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
228 read_pmu_cycle3     : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
240 report_diff_field2  : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
241 report_diff_field3  : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
242 report_diff_field4  : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
243 report_diff_field5  : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
246 report_srcline2     : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
250 indirect_return     : OK OK OK OK OK NG NG NG NG NG  OK OK OK OK OK NG NG NG NG NG
251 exception4          : NG OK OK OK OK SG SG SG SG SG  NZ NZ NZ NZ NZ SG SG SG SG SG
278 size_filter1        : OK OK OK OK OK OK OK OK OK NZ  OK OK OK OK OK NZ NZ NZ NZ NZ
279 size_filter2        : OK OK OK OK OK OK OK OK OK NZ  OK OK OK OK OK NZ NZ NZ NZ NZ
280 size_filter3        : OK OK OK OK OK OK OK OK OK NG  OK OK OK OK OK NG NG NG NG NG
281 agent_trace_toggle  : OK OK OK OK OK OK OK OK NG OK  NZ OK OK OK NZ OK NZ OK NZ OK

@namhyung
Copy link
Owner Author

namhyung commented Dec 8, 2023

Can you share your binary? It works fine on my system.

$ gcc -pg -o threads ~/project/uftrace/tests/s-thread.c -pthread

$ uftrace threads
# DURATION     TID     FUNCTION
            [  1005] | main() {
 553.592 us [  1005] |   pthread_create();
 450.193 us [  1005] |   pthread_create();
   2.083 ms [  1005] |   pthread_create();
            [  1005] |   pthread_create() {
            [  1009] | foo() {
            [  1009] |   a() 
            [  1009] |     b() {
   3.600 us [  1009] |       c();
  19.700 us [  1009] |     } /* b */
  28.300 us [  1009] |   } /* a */
  37.799 us [  1009] | } /* foo */
   1.536 ms [  1005] |   } /* pthread_create */
            [  1005] |   pthread_join() {
            [  1008] | foo() {
            [  1008] |   a() {
            [  1008] |     b() {
   3.500 us [  1008] |       c();
  20.399 us [  1008] |     } /* b */
  30.399 us [  1008] |   } /* a */
  39.999 us [  1008] | } /* foo */
            [  1011] | foo() {
            [  1011] |   a() {
            [  1011] |     b() {
   3.300 us [  1011] |       c();
  19.700 us [  1011] |     } /* b */
  28.299 us [  1011] |   } /* a */
  36.899 us [  1011] | } /* foo */
            [  1010] | foo() {
            [  1010] |   a() {
            [  1010] |     b() {
   3.900 us [  1010] |       c();
  20.999 us [  1010] |     } /* b */
  30.499 us [  1010] |   } /* a */
  40.399 us [  1010] | } /* foo */
   5.914 ms [  1005] |   } /* pthread_join */
   9.200 us [  1005] |   pthread_join();
   2.800 us [  1005] |   pthread_join();
   1.400 us [  1005] |   pthread_join();
  10.776 ms [  1005] | } /* main */

@honggyukim
Copy link
Collaborator

Can you share your binary? It works fine on my system.

Sure. I've attached the binary at t-thread.txt.

The file command output is as follows.

$ gcc -pg -o t-thread tests/s-thread.c -pthread

$ file t-thread 
t-thread: ELF 64-bit LSB pie executable, UCB RISC-V, RVC, double-float ABI, version 1 (SYSV), dynamically linked, interpreter /lib/ld-linux-riscv64-lp64d.so.1, BuildID[sha1]=8e200c3951dfc76ad56513a5b27d24871a0df660, for GNU/Linux 4.15.0, not stripped

@namhyung
Copy link
Owner Author

namhyung commented Dec 9, 2023

Oh, right. I missed a place to update the PLTGOT offset. My system enabled BIND_NOW by default so I couldn't check. Can you please test this?

diff --git a/libmcount/plthook.c b/libmcount/plthook.c
index 27537baf..42a638d8 100644
--- a/libmcount/plthook.c
+++ b/libmcount/plthook.c
@@ -762,7 +762,7 @@ static void update_pltgot(struct mcount_thread_data *mtdp, struct plthook_data *
                pthread_mutex_lock(&resolver_mutex);
 #endif
                if (!pd->resolved_addr[dyn_idx]) {
-                       int got_idx = 3 + dyn_idx;
+                       int got_idx = ARCH_PLTGOT_OFFSET + dyn_idx;
                        plthook_addr = mcount_arch_plthook_addr(pd, dyn_idx);
                        setup_pltgot(pd, got_idx, dyn_idx, (void *)plthook_addr);
                }

@honggyukim
Copy link
Collaborator

Thanks for the update. I see that it now works fine with your fix!

I just ran the runtest.py and see more failures but found that my RISC-V board doesn't have /proc/sys/kernel/perf_event_paranoid file so all the tests related events and pmu fails.

Here are the full list of failed-test.txt except for event and pmu tests.

$ cat failed-tests.txt | grep -v sched | grep -v pmu
Compiler                  gcc                            clang                        
Runtime test case         pg             finstrument-fu  pg             finstrument-fu
------------------------: O0 O1 O2 O3 Os O0 O1 O2 O3 Os  O0 O1 O2 O3 Os O0 O1 O2 O3 Os
007 library             : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
048 malloc_impl         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
052 nested_func         : NG OK OK OK OK NG OK OK OK OK  SK SK SK SK SK SK SK SK SK SK
058 arg_int             : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
059 arg_str             : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
060 arg_fmt             : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
062 arg_char            : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
063 retval              : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
065 arg_order           : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
074 lib_trigger         : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
075 lib_arg             : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
077 lib_replay_T        : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
082 arg_many            : NG NG NG NG NG SK SK SK SK SK  NG NG NG NG NG SK SK SK SK SK
084 arg_mixed           : NG NG NG NG NG SK SK SK SK SK  NG NG NG NG NG SK SK SK SK SK
085 arg_reg             : NG NG NG NG NG SK SK SK SK SK  NG NG NG NG NG SK SK SK SK SK
086 arg_stack           : NG NG NG NG NG SK SK SK SK SK  NG NG NG NG NG SK SK SK SK SK
087 arg_variadic        : NG NG NG NG NG SK SK SK SK SK  NG NG NG NG NG SK SK SK SK SK
102 dump_flamegraph     : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK OK NG OK OK OK
109 replay_time_A       : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
119 malloc_hook         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
120 malloc_tsd          : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
121 malloc_fork         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
124 exception           : OK NG NG NG NG OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
126 arg_regex           : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
127 arg_module          : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
140 dynamic_xray        : BI BI BI BI BI BI BI BI BI BI  BI BI BI BI BI BI BI BI BI BI
142 recv_multi          : OK OK OK OK OK NZ OK OK OK OK  OK OK OK OK OK OK OK OK OK OK
146 arg_std_string      : NG NG NG NG NG SK SK SK SK SK  NG NG NG NG NG SK SK SK SK SK
151 recv_runcmd         : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK OK OK OK NG OK
162 pltbind_now_pie     : OK OK OK OK OK OK OK OK OK OK  BI BI BI BI BI BI BI BI BI BI
168 lib_nested          : NG NG NG NG NG NG NG NG NG NG  OK OK OK OK OK OK OK OK OK OK
173 trigger_args        : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
182 thread_exit         : OK OK OK OK OK OK OK OK OK OK  NG NG NG NG NG NG NG NG NG NG
185 exception2          : NG OK OK OK OK OK OK OK OK OK  NG NG OK NG NG NG NG NG NG NG
186 exception3          : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG NG NG NG NG NG
189 replay_field2       : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
191 posix_spawn         : OK OK OK OK OK OK OK OK OK OK  NG NG NG NG NG NG NG NG NG NG
192 lib_name            : NG NG NG NG NG NG NG NG NG NG  OK OK OK OK OK OK OK OK OK OK
196 chrome_taskname     : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
201 arg_dwarf1          : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
202 arg_dwarf2          : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
203 arg_dwarf3          : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
204 arg_dwarf4          : NG NG NG NG NG SK SK SK SK SK  OK NG NG OK NG SK SK SK SK SK
205 arg_auto4           : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
206 arg_enum2           : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
213 arg_symbol          : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
214 signal_trigger      : OK OK OK OK OK OK OK OK NZ OK  OK OK OK OK OK OK OK OK OK OK
221 taskname_time       : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
231 arg_bound           : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
246 report_srcline2     : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
251 exception4          : NG OK OK OK OK SG SG SG SG SG  NG NG NG NG NG SG SG SG SG SG
254 arg_dwarf5          : NG NG NG NG NG SK SK SK SK SK  NG NG NG NG NG SK SK SK SK SK
255 arg_dwarf6          : OK OK OK OK OK SK SK SK SK SK  NG NG NG NG NG SK SK SK SK SK
257 arg_struct_replay   : NG OK OK OK OK SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
258 arg_struct_dump     : NG OK OK OK OK SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
282 agent_depth         : OK OK OK OK OK OK OK OK NG OK  OK OK OK OK OK OK OK OK NZ OK
283 agent_time          : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK OK OK NZ OK OK
285 agent_caller_filter : OK OK OK OK OK OK OK OK OK OK  OK NZ OK OK OK OK OK OK OK OK

@honggyukim
Copy link
Collaborator

honggyukim commented Dec 10, 2023

I see one of weird failure in 048 malloc_impl. It can be reproduced as follows.

$ gcc -pg -o t-malloc tests/s-malloc.c 
$ uftrace t-malloc 
# DURATION     TID     FUNCTION
            [208322] | main() {
   1.250 us [208322] |   malloc();
   0.750 us [208322] |   free();
   7.750 us [208322] | } /* main */

$ clang -pg -o t-malloc tests/s-malloc.c 
$ uftrace t-malloc 
WARN: child terminated by signal: 7: Bus error
uftrace: /home/user/work/uftrace/cmds/record.c:1441:update_session_maps
 ERROR: cannot find map files: No such file or directory

119, 120 and 121 have the same failures as 048 in clang compiled binaries.

048 malloc_impl         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
119 malloc_hook         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
120 malloc_tsd          : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
121 malloc_fork         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ

@honggyukim
Copy link
Collaborator

honggyukim commented Dec 10, 2023

I think we better focus on these failures.

$ cat failed-tests.txt | grep -v event | grep -v pmu | grep -v arg | grep -v sched | grep -v taskname
Compiler                  gcc                            clang                        
Runtime test case         pg             finstrument-fu  pg             finstrument-fu
------------------------: O0 O1 O2 O3 Os O0 O1 O2 O3 Os  O0 O1 O2 O3 Os O0 O1 O2 O3 Os
007 library             : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
048 malloc_impl         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
052 nested_func         : NG OK OK OK OK NG OK OK OK OK  SK SK SK SK SK SK SK SK SK SK
063 retval              : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
074 lib_trigger         : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
077 lib_replay_T        : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
102 dump_flamegraph     : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK OK NG OK OK OK
109 replay_time_A       : NG NG NG NG NG SK SK SK SK SK  OK OK OK OK OK SK SK SK SK SK
119 malloc_hook         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
120 malloc_tsd          : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
121 malloc_fork         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
124 exception           : OK NG NG NG NG OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
140 dynamic_xray        : BI BI BI BI BI BI BI BI BI BI  BI BI BI BI BI BI BI BI BI BI
142 recv_multi          : OK OK OK OK OK NZ OK OK OK OK  OK OK OK OK OK OK OK OK OK OK
151 recv_runcmd         : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK OK OK OK NG OK
162 pltbind_now_pie     : OK OK OK OK OK OK OK OK OK OK  BI BI BI BI BI BI BI BI BI BI
168 lib_nested          : NG NG NG NG NG NG NG NG NG NG  OK OK OK OK OK OK OK OK OK OK
182 thread_exit         : OK OK OK OK OK OK OK OK OK OK  NG NG NG NG NG NG NG NG NG NG
185 exception2          : NG OK OK OK OK OK OK OK OK OK  NG NG OK NG NG NG NG NG NG NG
186 exception3          : NG NG NG NG NG OK OK OK OK OK  NG NG NG NG NG NG NG NG NG NG
189 replay_field2       : NG NG NG NG NG NG NG NG NG NG  NG NG NG NG NG NG NG NG NG NG
191 posix_spawn         : OK OK OK OK OK OK OK OK OK OK  NG NG NG NG NG NG NG NG NG NG
192 lib_name            : NG NG NG NG NG NG NG NG NG NG  OK OK OK OK OK OK OK OK OK OK
214 signal_trigger      : OK OK OK OK OK OK OK OK NZ OK  OK OK OK OK OK OK OK OK OK OK
246 report_srcline2     : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK NG NG NG NG NG
251 exception4          : NG OK OK OK OK SG SG SG SG SG  NG NG NG NG NG SG SG SG SG SG
282 agent_depth         : OK OK OK OK OK OK OK OK NG OK  OK OK OK OK OK OK OK OK NZ OK
283 agent_time          : OK OK OK OK OK OK OK OK OK OK  OK OK OK OK OK OK OK NZ OK OK
285 agent_caller_filter : OK OK OK OK OK OK OK OK OK OK  OK NZ OK OK OK OK OK OK OK OK

@namhyung
Copy link
Owner Author

Can you please attach the t-malloc binary too?

@honggyukim
Copy link
Collaborator

Sure. Here it is. t-malloc.txt

@honggyukim
Copy link
Collaborator

It looks exception handling is broken as well.

$ ./runtest.py -vdp -O0 -c gcc 251
Start 1 tests without worker pool

Compiler                  gc
Runtime test case         pg
------------------------: O0
build command for library: g++ -o libexcept.so -fno-inline -fno-builtin -fno-ipa-cp -fno-omit-frame-pointer -D_FORTIFY_SOURCE=0  -pg -O0 -fno-ipa-sra  -shared -fPIC s-libexcept.cpp   
build command for executable: g++ -o t-libexcept-main -fno-inline -fno-builtin -fno-ipa-cp -fno-omit-frame-pointer -D_FORTIFY_SOURCE=0  -pg -O0 -fno-ipa-sra  s-libexcept-main.cpp    -Wl,-rpath,$ORIGIN -L.  -lexcept
test command: /home/user/work/uftrace/git/uftrace/uftrace live --no-pager --no-event --libmcount-path=/home/user/work/uftrace/git/uftrace   -N memcpy t-libexcept-main
terminate called after throwing an instance of 'std::runtime_error'
terminate called recursively
WARN: process crashed by signal 6: Aborted (si_code: -6)
WARN:  if this happens only with uftrace, please consider -e/--estimate-return option.

WARN: Backtrace from uftrace v0.14-76-g21efd ( riscv64 dwarf python3 tui perf sched dynamic )
WARN: =====================================
WARN: [2] (XXX::XXX[3f86d7a872] <= plthook_return[3f86daecd2])
WARN: [1] (XXX::XXX[2aaccc7af0] <= main[2aaccc7c60])
WARN: [0] (main[2aaccc7c56] <= __libc_start_main[3f86a8c808])
WARN: child terminated by signal: 6: Aborted
251 exception4          : SG

It still fails even without libcall and with the following changes.

diff --git a/arch/riscv64/mcount.S b/arch/riscv64/mcount.S
index e5fc3047..9a7bf9ea 100644
--- a/arch/riscv64/mcount.S
+++ b/arch/riscv64/mcount.S
@@ -3,6 +3,7 @@
 .text
 
 GLOBAL(_mcount)
+       ret
        /* setup frame pointer & return address */
        addi sp, sp, -80
        sd ra, 72(sp)
diff --git a/libmcount/wrap.c b/libmcount/wrap.c
index 30adcf09..ed94bad2 100644
--- a/libmcount/wrap.c
+++ b/libmcount/wrap.c
@@ -315,49 +315,11 @@ __visible_default int backtrace(void **buffer, int sz)
 
 __visible_default void __cxa_throw(void *exception, void *type, void *dest)
 {
-       struct mcount_thread_data *mtdp;
-
-       if (unlikely(real_cxa_throw == NULL))
-               mcount_hook_functions();
-
-       mtdp = get_thread_data();
-       if (!check_thread_data(mtdp)) {
-               pr_dbg2("%s: exception thrown from [%d]\n", __func__, mtdp->idx);
-
-               mtdp->in_exception = true;
-
-               /*
-                * restore return addresses so that it can unwind stack
-                * frames safely during the exception handling.
-                * It pairs to mcount_rstack_reset_exception().
-                */
-               mcount_rstack_restore(mtdp);
-       }
-
        real_cxa_throw(exception, type, dest);
 }
 
 __visible_default void __cxa_rethrow(void)
 {
-       struct mcount_thread_data *mtdp;
-
-       if (unlikely(real_cxa_rethrow == NULL))
-               mcount_hook_functions();
-
-       mtdp = get_thread_data();
-       if (!check_thread_data(mtdp)) {
-               pr_dbg2("%s: exception rethrown from [%d]\n", __func__, mtdp->idx);
-
-               mtdp->in_exception = true;
-
-               /*
-                * restore return addresses so that it can unwind stack
-                * frames safely during the exception handling.
-                * It pairs to mcount_rstack_reset_exception()
-                */
-               mcount_rstack_restore(mtdp);
-       }
-
        real_cxa_rethrow();
 }
 
$ uftrace record --no-libcall t-libexcept-main 
terminate called after throwing an instance of 'std::runtime_error'
terminate called recursively
WARN: child terminated by signal: 6: Aborted

@honggyukim
Copy link
Collaborator

The binaries are attached here.

@namhyung
Copy link
Owner Author

namhyung commented Dec 11, 2023

Is this built by clang? I cannot reproduce.

$ uftrace t-malloc 
# DURATION     TID     FUNCTION
            [   968] | main() {
  52.612 us [   968] |   malloc();
   1.100 us [   968] |   free();
 455.204 us [   968] | } /* main */

And the exception handling works.

$ uftrace t-libexcept-main
# DURATION     TID     FUNCTION
            [  1057] | main() {
            [  1057] |   XXX::XXX() {
 852.786 us [  1057] |     XXX::XXX();
 988.984 us [  1057] |   } /* XXX::XXX */
   1.099 ms [  1057] | } /* main */
            [  1057] | YYY::YYY() {
 104.198 us [  1057] |   __cxa_allocate_exception();
   6.100 us [  1057] |   std::runtime_error::runtime_error();
 302.495 us [  1057] | } /* YYY::YYY */

@honggyukim
Copy link
Collaborator

Is this built by clang? I cannot reproduce.

Yes, it's built by clang.

$ ./runtest.py malloc
Start 4 tests with 4 worker

Compiler                  gcc                            clang                        
Runtime test case         pg             finstrument-fu  pg             finstrument-fu
------------------------: O0 O1 O2 O3 Os O0 O1 O2 O3 Os  O0 O1 O2 O3 Os O0 O1 O2 O3 Os
048 malloc_impl         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
119 malloc_hook         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
120 malloc_tsd          : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ
121 malloc_fork         : OK OK OK OK OK OK OK OK OK OK  NZ NZ NZ NZ NZ NZ NZ NZ NZ NZ

251 exception4 fails both gcc and clang.

$ ./runtest.py 251
Start 1 tests without worker pool

Compiler                  gcc                            clang                        
Runtime test case         pg             finstrument-fu  pg             finstrument-fu
------------------------: O0 O1 O2 O3 Os O0 O1 O2 O3 Os  O0 O1 O2 O3 Os O0 O1 O2 O3 Os
251 exception4          : SG SG SG SG SG SG SG SG SG SG  SG SG SG SG SG SG SG SG SG SG

@honggyukim
Copy link
Collaborator

I think fixing all those failures might be difficult right now so it might be better to merge the current implementation with #1853 (comment), then create separate issues for these problems.

@namhyung
Copy link
Owner Author

I can reproduce the malloc failure with clang.

Program received signal SIGBUS, Bus error.
0x0000003ff7ee224a in __GI__IO_link_in (fp=fp@entry=0x23d19 <malloc.buf+72864>) at genops.c:95
95	genops.c: No such file or directory.
(gdb) bt
#0  0x0000003ff7ee224a in __GI__IO_link_in (fp=fp@entry=0x23d19 <malloc.buf+72864>) at genops.c:95
#1  0x0000003ff7ee14ac in _IO_new_file_init_internal (fp=fp@entry=0x23d19 <malloc.buf+72864>) at fileops.c:114
#2  0x0000003ff7ed8fc2 in __fopen_internal (filename=filename@entry=0x3ff7fce848 "/proc/self/maps", mode=mode@entry=0x3ff7fce840 "r",
    is32=is32@entry=1) at iofopen.c:74
#3  0x0000003ff7ed903e in _IO_new_fopen (filename=filename@entry=0x3ff7fce848 "/proc/self/maps", mode=mode@entry=0x3ff7fce840 "r")
    at iofopen.c:86
#4  0x0000003ff7fb7d28 in record_proc_maps (dirname=<optimized out>, sess_id=<optimized out>, sinfo=<optimized out>)
    at /home/namhyung/project/uftrace/libmcount/record.c:1125
#5  0x0000003ff7fb4b3c in mcount_startup () at /home/namhyung/project/uftrace/libmcount/mcount.c:1922
#6  mcount_startup () at /home/namhyung/project/uftrace/libmcount/mcount.c:1805
#7  0x0000003ff7febbfa in call_init (l=<optimized out>, argc=argc@entry=1, argv=argv@entry=0x3ffffff378, env=env@entry=0x3ffffff388)
    at dl-init.c:74
#8  0x0000003ff7febcaa in call_init (env=0x3ffffff388, argv=0x3ffffff378, argc=1, l=<optimized out>) at dl-init.c:37
#9  _dl_init (main_map=0x3ff7fff1e0, argc=<optimized out>, argv=0x3ffffff378, env=0x3ffffff388) at dl-init.c:121
#10 0x0000003ff7fe1bd0 in _dl_start_user () from /lib/ld-linux-riscv64-lp64d.so.1
Backtrace stopped: frame did not save the PC

@namhyung
Copy link
Owner Author

Looks like the malloc issue is due to alignment. The following change would make it work.

diff --git a/tests/s-malloc.c b/tests/s-malloc.c
index 9afb0e42..f94f67e3 100644
--- a/tests/s-malloc.c
+++ b/tests/s-malloc.c
@@ -10,7 +10,7 @@ int free_count;

 void *malloc(size_t size)
 {
-       static char buf[MALLOC_BUFSIZE];
+       static char buf[MALLOC_BUFSIZE] __attribute__((aligned(16)));
        static unsigned alloc_size;
        void *ptr;

@honggyukim
Copy link
Collaborator

Thanks. I can also see that the above change makes it work, but do we always have to fix the target program?

@namhyung
Copy link
Owner Author

namhyung commented Dec 14, 2023

And I cannot reproduce the exception issue.

namhyung@starfive:~/tmp$ uftrace t-libexcept-main
# DURATION     TID     FUNCTION
            [ 10837] | main() {
 103.002 us [ 10837] |   XXX::XXX();
 108.502 us [ 10837] | } /* main */
  20.500 us [ 10837] | YYY::YYY();

@namhyung
Copy link
Owner Author

but do we always have to fix the target program?

No, but this code is tricky. Normally malloc() should return an aligned memory region.

@honggyukim
Copy link
Collaborator

AFAIK, malloc() returns 8 byte aligned pointer and I also see that the following change is also fine in clang.

static char buf[MALLOC_BUFSIZE] __attribute__((aligned(8)));

@namhyung
Copy link
Owner Author

Oh... wait.. I think I tested on a wrong branch. Let me take a look more.

@honggyukim
Copy link
Collaborator

I can add a debugging log as follow.

diff --git a/tests/s-malloc.c b/tests/s-malloc.c
index 9afb0e42..89701ebe 100644
--- a/tests/s-malloc.c
+++ b/tests/s-malloc.c
@@ -14,6 +14,7 @@ void *malloc(size_t size)
        static unsigned alloc_size;
        void *ptr;
 
+       fprintf(stderr, "buf = %p (%lu)\n", buf, (unsigned long)buf);
        size = ALIGN(size, 16);
        if (alloc_size + size > sizeof(buf))
                return NULL;

Then it shows the clang compiled binary shows the alignment is broken inbuf.

$ gcc -pg -o t-malloc tests/s-malloc.c 
$ ./t-malloc
buf = 0x2ab7cc30a0 (183472238752)

$ clang -pg -o t-malloc.clang tests/s-malloc.c 
$ ./t-malloc.clang 
buf = 0x1208d (73869)

The address of buf isn't aligned in t-malloc.clang.

@honggyukim
Copy link
Collaborator

Another issue here is that attaching uftrace makes the fprintf statement is printed multiple times in both gcc and clang compiled binaries.

t-malloc (gcc compiled)

$ uftrace record --no-libcall t-malloc       
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)
buf = 0x2ad81520a0 (184013889696)

t-malloc.clang (clang compiled)

$ uftrace record --no-libcall t-malloc.clang 
buf = 0x1208d (73869)
buf = 0x1208d (73869)
buf = 0x1208d (73869)
buf = 0x1208d (73869)
WARN: child terminated by signal: 7: Bus error
uftrace: /home/honggyu/work/uftrace/git/uftrace/cmds/record.c:1441:update_session_maps
 ERROR: cannot find map files: No such file or directory

@namhyung
Copy link
Owner Author

AFAIK, malloc() returns 8 byte aligned pointer and I also see that the following change is also fine in clang.

It depends on the implementation. And this code uses 16 byte alignment.

@honggyukim
Copy link
Collaborator

honggyukim commented Dec 14, 2023

The issue here is that it's not related to libcall. I see that renaming malloc, free to my_malloc, my_free fixes all the problems in both gcc and clang compiled binaries.
(I also see that the realloc function here isn't used anywhere so we can remove it.)

@honggyukim
Copy link
Collaborator

Maybe uftrace got confused by those malloc and free function names somehow.

@namhyung
Copy link
Owner Author

The point of the test is to check if the target process implements its own malloc() and free(). And uftrace (libmcount) uses malloc and free internally that means it calls back to the target code inside libmcount. The purpose of the test is to verify it works.

@namhyung
Copy link
Owner Author

I think I can close this issue with the change. Please file a separate issue for remaining bugs.

@honggyukim
Copy link
Collaborator

Sure. I think the current change is enough for the basic PLT hooking implementation. Let's discuss in a separate issues. Thanks for the work!

@namhyung namhyung added this to the v0.15 milestone Dec 18, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants