record: Library functions not traced
clementguidi opened this issue · 5 comments
clementguidi commented
Hey,
On my machine (Oracle 7 x86_64 GCC-6.3), f7ecadb breaks test 001 basic and many more. getpid() is missing from the output (see below).
Is that related to entry size?
Compiler gc
Runtime test case pg
------------------------: O0
build command: gcc -o t-abc -fno-inline -fno-builtin -fno-ipa-cp -fno-omit-frame-pointer -D_FORTIFY_SOURCE=0 -pg -O0 -fno-ipa-sra s-abc.c
test command: /localdisk/uftrace/uftrace live --no-pager --no-event --libmcount-path=/localdisk/uftrace -N memcpy t-abc
=========== original ===========
# DURATION TID FUNCTION
[ 25525] | main() {
[ 25525] | a() {
[ 25525] | b() {
0.629 us [ 25525] | c();
1.889 us [ 25525] | } /* b */
2.242 us [ 25525] | } /* a */
3.181 us [ 25525] | } /* main */
=========== result ===========
main() {
a() {
b() {
c();
} /* b */
} /* a */
} /* main */
=========== expected ===========
main() {
a() {
b() {
c() {
getpid();
} /* c */
} /* b */
} /* a */
} /* main */
001 basic : NG
namhyung commented
Probably. Can you please run the test program (or anything simple) with -v option? And also please share the output of readelf -SW <your-binary>.
clementguidi commented
Right, I spotted the plthook: cannot find REL(A)ENT size line.
I'm using tests/s-abc.c as source.
$ gcc -o t-abc -fno-inline -fno-builtin -fno-ipa-cp -fno-omit-frame-pointer -D_FORTIFY_SOURCE=0 -pg -O0 -fno-ipa-sra s-abc.c
$ uftrace -v t-abc
uftrace: running uftrace v0.14-97-gf7ec ( x86_64 dwarf python3 tui perf sched dynamic )
uftrace: checking binary t-abc
uftrace: using /usr/local/lib/uftrace/libmcount.so library for tracing
uftrace: creating 3 thread(s) for recording
mcount: initializing mcount library
plthook: setup PLT hooking "/localdisk/uftrace/tests/t-abc"
plthook: cannot find REL(A)ENT size
mcount: mcount setup done
mcount: new session started: d1d99009924f59b3: t-abc
mcount: mcount trace finished
mcount: exit from libmcount
uftrace: child terminated with exit code: 0
uftrace: cannot read build-id section
uftrace: reading /tmp/uftrace-live-OTKMLH/task.txt file
uftrace: flushing /uftrace-d1d99009924f59b3-27908-000
uftrace: live-record finished..
uftrace: start live-replaying...
uftrace: reading /tmp/uftrace-live-OTKMLH/task.txt file
fstack: fixup for some special functions
uftrace: add field "duration"
uftrace: add field "tid"
# DURATION TID FUNCTION
[ 27908] | main() {
[ 27908] | a() {
[ 27908] | b() {
0.530 us [ 27908] | c();
1.993 us [ 27908] | } /* b */
2.357 us [ 27908] | } /* a */
3.267 us [ 27908] | } /* main */
uftrace: removing /tmp/uftrace-live-OTKMLH directory
$ readelf -SW t-abc
There are 27 section headers, starting at offset 0x1ab8:
Section Headers:
[Nr] Name Type Address Off Size ES Flg Lk Inf Al
[ 0] NULL 0000000000000000 000000 000000 00 0 0 0
[ 1] .interp PROGBITS 0000000000400238 000238 00001c 00 A 0 0 1
[ 2] .note.ABI-tag NOTE 0000000000400254 000254 000020 00 A 0 0 4
[ 3] .hash HASH 0000000000400278 000278 000034 04 A 4 0 8
[ 4] .dynsym DYNSYM 00000000004002b0 0002b0 0000c0 18 A 5 1 8
[ 5] .dynstr STRTAB 0000000000400370 000370 000060 00 A 0 0 1
[ 6] .gnu.version VERSYM 00000000004003d0 0003d0 000010 02 A 4 0 2
[ 7] .gnu.version_r VERNEED 00000000004003e0 0003e0 000020 00 A 5 1 8
[ 8] .rela.plt RELA 0000000000400400 000400 0000a8 18 AI 4 20 8
[ 9] .init PROGBITS 00000000004004a8 0004a8 00001a 00 AX 0 0 4
[10] .plt PROGBITS 00000000004004d0 0004d0 000080 10 AX 0 0 16
[11] .text PROGBITS 0000000000400550 000550 00027c 00 AX 0 0 16
[12] .fini PROGBITS 00000000004007cc 0007cc 000009 00 AX 0 0 4
[13] .rodata PROGBITS 00000000004007d8 0007d8 000004 04 AM 0 0 4
[14] .eh_frame_hdr PROGBITS 00000000004007dc 0007dc 00005c 00 A 0 0 4
[15] .eh_frame PROGBITS 0000000000400838 000838 000184 00 A 0 0 8
[16] .init_array INIT_ARRAY 0000000000600e48 000e48 000008 08 WA 0 0 8
[17] .fini_array FINI_ARRAY 0000000000600e50 000e50 000008 08 WA 0 0 8
[18] .jcr PROGBITS 0000000000600e58 000e58 000008 00 WA 0 0 8
[19] .dynamic DYNAMIC 0000000000600e60 000e60 0001a0 10 WA 5 0 8
[20] .got.plt PROGBITS 0000000000601000 001000 000050 08 WA 0 0 8
[21] .data PROGBITS 0000000000601050 001050 000010 00 WA 0 0 8
[22] .bss NOBITS 0000000000601060 001060 000008 00 WA 0 0 16
[23] .comment PROGBITS 0000000000000000 001060 000042 01 MS 0 0 1
[24] .symtab SYMTAB 0000000000000000 0010a8 0006c0 18 25 48 8
[25] .strtab STRTAB 0000000000000000 001768 00026e 00 0 0 1
[26] .shstrtab STRTAB 0000000000000000 0019d6 0000e2 00 0 0 1
Key to Flags:
W (write), A (alloc), X (execute), M (merge), S (strings), I (info),
L (link order), O (extra OS processing required), G (group), T (TLS),
C (compressed), x (unknown), o (OS specific), E (exclude),
l (large), p (processor specific)
namhyung commented
Ok, it seems the dynamic section doesn't have the data. But the section header (.rela.plt) has the entry size so we can fallback to read it.
namhyung commented
How about this?
diff --git a/libmcount/plthook.c b/libmcount/plthook.c
index 59f8e00b..bbc9c433 100644
--- a/libmcount/plthook.c
+++ b/libmcount/plthook.c
@@ -246,8 +246,22 @@ static int find_got(struct uftrace_elf_data *elf, struct uftrace_elf_iter *iter,
}
if (jmprel_ent_size == 0) {
- pr_dbg("cannot find REL(A)ENT size\n");
- return 0;
+ /*
+ * Some compilers didn't generate DT_REL(A)ENT entry.
+ * Check the section header for the entry size.
+ */
+ elf_for_each_shdr(elf, &sec_iter) {
+ if (sec_iter.shdr.sh_type == SHT_REL ||
+ sec_iter.shdr.sh_type == SHT_RELA) {
+ jmprel_ent_size = sec_iter.shdr.sh_entsize;
+ break;
+ }
+ }
+
+ if (jmprel_ent_size == 0) {
+ pr_dbg("cannot find REL(A)ENT size\n");
+ return 0;
+ }
}
elf_for_each_shdr(elf, &sec_iter) {clementguidi commented
That solves the problem on my machine. Thank you.