tracing library calls even if it has no PLT #592

namhyung · 2018-11-12T11:59:25Z

This change will enable tracing library calls have no PLT. As PLT is needed to trace those libcalls, uftrace make up a trampoline and fill necessary instructions there.

The code is available at review/libcall-noplt-v1 branch.

Before:

$ uftrace --force /usr/bin/pwd
/home/namhyung/tmp/uftrace
WARN: cannot open record data: /tmp/uftrace-live-2W13XP: No data available

After:

$ uftrace -a --force /usr/bin/pwd
/home/namhyung/tmp/uftrace
# DURATION     TID     FUNCTION
  97.815 us [  1201] | getenv("POSIXLY_CORRECT") = "NULL";
   0.422 us [  1201] | strrchr("/usr/bin/pwd", '/') = "/pwd";
  32.586 us [  1201] | setlocale();
   0.750 us [  1201] | bindtextdomain();
   0.370 us [  1201] | textdomain();
   0.165 us [  1201] | __cxa_atexit();
   3.011 us [  1201] | getopt_long();
   3.858 us [  1201] | getcwd();
   1.697 us [  1201] | puts("/home/namhyung/tmp/uftrace") = 27;
   0.156 us [  1201] | free(0x55f7ab1ad790);
   0.183 us [  1201] | __fpending();
   0.340 us [  1201] | fileno();
   0.157 us [  1201] | __freading();
   0.058 us [  1201] | __freading();
   4.090 us [  1201] | fflush();
   1.051 us [  1201] | fclose(0x7f3fc47745c0) = 0;
   0.134 us [  1201] | __fpending();
   0.072 us [  1201] | fileno();
   0.123 us [  1201] | __freading();
   0.058 us [  1201] | __freading();
   0.149 us [  1201] | fflush();
   0.755 us [  1201] | fclose(0x7f3fc47744e0) = 0;

The text was updated successfully, but these errors were encountered:

namhyung · 2018-11-16T07:22:53Z

Pushed review/libcall-noplt-v2

Changelog:

use address of reloc entry as symbol address

honggyukim · 2018-11-19T02:17:29Z

In my system, /usr/bin/pwd has PLT. Is there any way for me to test this? -fno-plt also seems to generate PLT section as well.

namhyung · 2018-11-20T08:34:16Z

What's the version of gcc? Could you (force) trace the pwd binary?

namhyung · 2018-11-22T06:55:38Z

Pushed review/libcall-noplt-v3

Changelog:

reduce size of trampoline
skip some libraries to avoid crash

honggyukim · 2018-11-22T07:03:33Z

What's the version of gcc? Could you (force) trace the pwd binary?

I use gcc-5.5.0 and pwd binary is traceable using uftrace in master branch.

$ uftrace --force /bin/pwd
/home/honggyu/work/uftrace/git/uftrace
# DURATION     TID     FUNCTION
   1.727 us [116277] | getenv();
   1.100 us [116277] | strrchr();
  79.745 us [116277] | setlocale();
   2.823 us [116277] | bindtextdomain();
   1.556 us [116277] | textdomain();
   1.107 us [116277] | __cxa_atexit();
   8.123 us [116277] | getopt_long();
   8.687 us [116277] | getcwd();
   3.686 us [116277] | puts();
   1.190 us [116277] | free();
   1.330 us [116277] | __fpending();
   1.084 us [116277] | fileno();
   1.013 us [116277] | __freading();
   0.187 us [116277] | __freading();
   7.344 us [116277] | fflush();
   2.847 us [116277] | fclose();
   0.180 us [116277] | __fpending();
   0.163 us [116277] | fileno();
   0.153 us [116277] | __freading();
   0.133 us [116277] | __freading();
   0.217 us [116277] | fflush();
   1.027 us [116277] | fclose();

namhyung · 2018-11-22T07:10:27Z

Ah, you said it has PLT. OK then. Could you please build a simple program (abc.c) with -fno-plt and show me the first few entry in the .plt section?

honggyukim · 2018-11-22T08:28:12Z

Hmm.. gcc-5.5 doesn't have -fno-plt option.

$ gcc --version
gcc (Ubuntu 5.5.0-12ubuntu1~16.04) 5.5.0 20171010
Copyright (C) 2015 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

$ gcc -fno-plt -pg -g tests/s-abc.c
gcc: error: unrecognized command line option ‘-fno-plt’

So I tried it with gcc-8 again.

$ gcc-8 -pg -g tests/s-abc.c
$ uftrace -a a.out
# DURATION     TID     FUNCTION
   1.573 us [118669] | __monstartup();
   1.180 us [118669] | __cxa_atexit();
            [118669] | main(1, 0x7ffdd617b188) {
            [118669] |   a() {
            [118669] |     b() {
            [118669] |       c() {
   1.111 us [118669] |         getpid() = 0x1cf8d;
   5.710 us [118669] |       } = 18669; /* c */
   6.630 us [118669] |     } = 18670; /* b */
   7.451 us [118669] |   } = 18669; /* a */
  10.037 us [118669] | } = 0; /* main */

Tested with -fno-plt again.

$ gcc-8 -fno-plt -pg -g tests/s-abc.c
$ uftrace -a a.out
# DURATION     TID     FUNCTION
   1.710 us [118707] | __monstartup();
   1.120 us [118707] | __cxa_atexit();
            [118707] | main(1, 0x7fff9a134f58) {
            [118707] |   a() {
            [118707] |     b() {
   0.250 us [118707] |       c() = 18707;
   2.117 us [118707] |     } = 18708; /* b */
   2.984 us [118707] |   } = 18707; /* a */
   5.311 us [118707] | } = 0; /* main */

But it's very strange that function c returns different value. It also doesn't trace getpid as well.
Here is the full disassemble output for .plt section and it doesn't have getpid.

Disassembly of section .plt:

0000000000400510 <__libc_start_main@plt-0x10>:
  400510:       ff 35 f2 0a 20 00       pushq  0x200af2(%rip)        # 601008 <_GLOBAL_OFFSET_TABLE_+0x8>
  400516:       ff 25 f4 0a 20 00       jmpq   *0x200af4(%rip)        # 601010 <_GLOBAL_OFFSET_TABLE_+0x10>
  40051c:       0f 1f 40 00             nopl   0x0(%rax)

0000000000400520 <__libc_start_main@plt>:
  400520:       ff 25 f2 0a 20 00       jmpq   *0x200af2(%rip)        # 601018 <_GLOBAL_OFFSET_TABLE_+0x18>
  400526:       68 00 00 00 00          pushq  $0x0
  40052b:       e9 e0 ff ff ff          jmpq   400510 <_init+0x20>

0000000000400530 <__monstartup@plt>:
  400530:       ff 25 ea 0a 20 00       jmpq   *0x200aea(%rip)        # 601020 <_GLOBAL_OFFSET_TABLE_+0x20>
  400536:       68 01 00 00 00          pushq  $0x1
  40053b:       e9 d0 ff ff ff          jmpq   400510 <_init+0x20>

0000000000400540 <mcount@plt>:
  400540:       ff 25 e2 0a 20 00       jmpq   *0x200ae2(%rip)        # 601028 <_GLOBAL_OFFSET_TABLE_+0x28>
  400546:       68 02 00 00 00          pushq  $0x2
  40054b:       e9 c0 ff ff ff          jmpq   400510 <_init+0x20>

0000000000400550 <__cxa_atexit@plt>:
  400550:       ff 25 da 0a 20 00       jmpq   *0x200ada(%rip)        # 601030 <_GLOBAL_OFFSET_TABLE_+0x30>
  400556:       68 03 00 00 00          pushq  $0x3
  40055b:       e9 b0 ff ff ff          jmpq   400510 <_init+0x20>

The function c doesn't call getpid anyway.

00000000004006a8 <c>:
  4006a8:       55                      push   %rbp
  4006a9:       48 89 e5                mov    %rsp,%rbp
  4006ac:       e8 8f fe ff ff          callq  400540 <mcount@plt>
  4006b1:       ff 15 29 09 20 00       callq  *0x200929(%rip)        # 600fe0 <_DYNAMIC+0x1d0>
  4006b7:       89 c1                   mov    %eax,%ecx
  4006b9:       ba 89 b5 f8 14          mov    $0x14f8b589,%edx
  4006be:       89 c8                   mov    %ecx,%eax
  4006c0:       f7 ea                   imul   %edx
  4006c2:       c1 fa 0d                sar    $0xd,%edx
  4006c5:       89 c8                   mov    %ecx,%eax
  4006c7:       c1 f8 1f                sar    $0x1f,%eax
  4006ca:       29 c2                   sub    %eax,%edx
  4006cc:       89 d0                   mov    %edx,%eax
  4006ce:       69 c0 a0 86 01 00       imul   $0x186a0,%eax,%eax
  4006d4:       29 c1                   sub    %eax,%ecx
  4006d6:       89 c8                   mov    %ecx,%eax
  4006d8:       5d                      pop    %rbp
  4006d9:       c3                      retq

It seems that callq *0x200929(%rip) is to call getpid here, but it doesn't show getpid with review/libcall-noplt-v3 as well.

namhyung · 2018-11-28T07:13:31Z

It seems that callq *0x200929(%rip) is to call getpid here, but it doesn't show getpid with review/libcall-noplt-v3 as well.

Yes, as you showed it didn't have the getpid entry in the PLT. Strange thing is that it still generated .plt section even with -fno-plt option. Maybe you also need to pass something like -Wl,-z,now to suppress it.

namhyung · 2018-11-28T08:17:32Z

Pushed review/libcall-noplt-v4

Changelog:

skip tracing functions when creating trampoline (they will be called directly)
add a test case

DanielTimLee · 2018-12-04T16:53:02Z

Tested on Manjaro Linux (Arch Linux), and it works great!
On my environment, most of the coreutils commands don't have PLT section.

Really thrilled with using this feature!

log

$ readelf -S /usr/bin/mv | grep plt
$ readelf -S /usr/bin/pwd | grep plt
$ readelf -S /usr/bin/ls | grep plt
$ uftrace -a --force /usr/bin/ls
# DURATION     TID     FUNCTION
 128.716 us [  4952] | strrchr("/usr/bin/ls", '/') = "/ls";
  81.590 us [  4952] | setlocale();
   0.911 us [  4952] | bindtextdomain();
   0.582 us [  4952] | textdomain();
   0.269 us [  4952] | __cxa_atexit();
   1.660 us [  4952] | isatty();
   1.111 us [  4952] | getenv("QUOTING_STYLE") = "NULL";
   0.515 us [  4952] | getenv("COLUMNS") = "NULL";
   1.073 us [  4952] | ioctl(1, 21523, 0x7ffc3ba10290) = -1;
   0.389 us [  4952] | getenv("TABSIZE") = "NULL";
   5.343 us [  4952] | getopt_long();
   0.423 us [  4952] | getenv("LS_BLOCK_SIZE") = "NULL";
   0.409 us [  4952] | getenv("BLOCK_SIZE") = "NULL";
   0.464 us [  4952] | getenv("BLOCKSIZE") = "NULL";
   0.350 us [  4952] | getenv("POSIXLY_CORRECT") = "NULL";
   0.287 us [  4952] | getenv("BLOCK_SIZE") = "NULL";
   0.159 us [  4952] | __errno_location();
   0.286 us [  4952] | malloc(56) = 0x56400ec7f9d0;
   0.348 us [  4952] | memcpy(0x56400ec7f9d0, 0x56400ce1b520, 56);
   0.115 us [  4952] | __errno_location();
   0.163 us [  4952] | malloc(56) = 0x56400ec4d280;
   0.170 us [  4952] | memcpy(0x56400ec4d280, 0x56400ce1b520, 56);
   0.380 us [  4952] | getenv("TZ") = "NULL";
   0.208 us [  4952] | malloc(128) = 0x56400ec600e0;
   2.981 us [  4952] | malloc(20000) = 0x56400ecd68f0;
   0.293 us [  4952] | malloc(32) = 0x56400ecdb720;
   0.347 us [  4952] | strlen(".") = 1;
   0.253 us [  4952] | malloc(2) = 0x56400ecdb750;
   0.204 us [  4952] | memcpy(0x56400ecdb750, 0x56400ce12f95, 2);
   0.104 us [  4952] | __errno_location();
   7.142 us [  4952] | opendir();
  20.885 us [  4952] | readdir();
   2.568 us [  4952] | closedir();
   2.566 us [  4952] | _setjmp();
   0.256 us [  4952] | free(0x56400ecdb750);
   0.196 us [  4952] | free(0);
   0.173 us [  4952] | free(0x56400ecdb720);
   0.370 us [  4952] | __fpending();
   0.285 us [  4952] | fileno();
   0.280 us [  4952] | __freading();
   0.544 us [  4952] | fflush();
   1.323 us [  4952] | fclose(0x7fbb9692c5c0) = 0;
   0.122 us [  4952] | fflush();
   0.880 us [  4952] | fclose(0x7fbb9692c4e0) = 0;
(END)

honggyukim · 2018-12-07T04:46:04Z

I don't see library calls in my Ubuntu 17.04 machine.

$ uftrace tests/t-arg
# DURATION     TID     FUNCTION
            [ 32597] | main() {
            [ 32597] |   foo() {
   0.094 us [ 32597] |     bar();
   0.039 us [ 32597] |     bar();
   0.038 us [ 32597] |     bar();
   0.877 us [ 32597] |   } /* foo */
   0.093 us [ 32597] |   many();
            [ 32597] |   pass() {
   0.041 us [ 32597] |     check();
   0.196 us [ 32597] |   } /* pass */
   1.586 us [ 32597] | } /* main */

gcc version is 6.3.0

$ gcc --version
gcc (Ubuntu 6.3.0-12ubuntu2) 6.3.0 20170406

Please see the detail logs below.

objdump output

Disassembly of section .plt:

0000000000000720 <.plt>:
 720:   ff 35 62 18 20 00       pushq  0x201862(%rip)        # 201f88 <_GLOBAL_OFFSET_TABLE_+0x8>
 726:   ff 25 64 18 20 00       jmpq   *0x201864(%rip)        # 201f90 <_GLOBAL_OFFSET_TABLE_+0x10>    
 72c:   0f 1f 40 00             nopl   0x0(%rax)

Disassembly of section .plt.got:

0000000000000730 <.plt.got>:
 730:   ff 25 6a 18 20 00       jmpq   *0x20186a(%rip)        # 201fa0 <__stack_chk_fail@GLIBC_2.4>
 736:   66 90                   xchg   %ax,%ax
 738:   ff 25 7a 18 20 00       jmpq   *0x20187a(%rip)        # 201fb8 <strcmp@GLIBC_2.2.5>
 73e:   66 90                   xchg   %ax,%ax
 740:   ff 25 7a 18 20 00       jmpq   *0x20187a(%rip)        # 201fc0 <__monstartup@GLIBC_2.2.5>
 746:   66 90                   xchg   %ax,%ax
 748:   ff 25 92 18 20 00       jmpq   *0x201892(%rip)        # 201fe0 <__cxa_atexit@GLIBC_2.2.5>
 74e:   66 90                   xchg   %ax,%ax
 750:   ff 25 92 18 20 00       jmpq   *0x201892(%rip)        # 201fe8 <atoi@GLIBC_2.2.5>
 756:   66 90                   xchg   %ax,%ax
 758:   ff 25 9a 18 20 00       jmpq   *0x20189a(%rip)        # 201ff8 <__cxa_finalize@GLIBC_2.2.5>
 75e:   66 90                   xchg   %ax,%ax

readelf -d output

$ readelf -d t-arg

Dynamic section at offset 0x1dc0 contains 24 entries:
  Tag        Type                         Name/Value
 0x0000000000000001 (NEEDED)             Shared library: [libc.so.6]
 0x000000000000000c (INIT)               0x700
 0x000000000000000d (FINI)               0xc7c
 0x0000000000000019 (INIT_ARRAY)         0x201da8
 0x000000000000001b (INIT_ARRAYSZ)       8 (bytes)
 0x000000000000001a (FINI_ARRAY)         0x201db0
 0x000000000000001c (FINI_ARRAYSZ)       8 (bytes)
 0x000000006ffffef5 (GNU_HASH)           0x298
 0x0000000000000005 (STRTAB)             0x410
 0x0000000000000006 (SYMTAB)             0x2c0
 0x000000000000000a (STRSZ)              218 (bytes)
 0x000000000000000b (SYMENT)             24 (bytes)
 0x0000000000000015 (DEBUG)              0x0
 0x0000000000000003 (PLTGOT)             0x201f80
 0x0000000000000007 (RELA)               0x538
 0x0000000000000008 (RELASZ)             456 (bytes)
 0x0000000000000009 (RELAENT)            24 (bytes)
 0x000000000000001e (FLAGS)              BIND_NOW
 0x000000006ffffffb (FLAGS_1)            Flags: NOW PIE
 0x000000006ffffffe (VERNEED)            0x508
 0x000000006fffffff (VERNEEDNUM)         1
 0x000000006ffffff0 (VERSYM)             0x4ea
 0x000000006ffffff9 (RELACOUNT)          7
 0x0000000000000000 (NULL)               0x0

readelf -r output

$ readelf -r t-arg

Relocation section '.rela.dyn' at offset 0x538 contains 19 entries:
  Offset          Info           Type           Sym. Value    Sym. Name + Addend
000000201da8  000000000008 R_X86_64_RELATIVE                    8b0
000000201db0  000000000008 R_X86_64_RELATIVE                    870
000000201fd0  000000000008 R_X86_64_RELATIVE                    c85
000000202008  000000000008 R_X86_64_RELATIVE                    202008
000000202010  000000000008 R_X86_64_RELATIVE                    ca8
000000202018  000000000008 R_X86_64_RELATIVE                    caa
000000202020  000000000008 R_X86_64_RELATIVE                    cac
000000201f98  000100000006 R_X86_64_GLOB_DAT 0000000000000000 _ITM_deregisterTMClone + 0
000000201fa0  000200000006 R_X86_64_GLOB_DAT 0000000000000000 __stack_chk_fail@GLIBC_2.4 + 0
000000201fa8  000300000006 R_X86_64_GLOB_DAT 0000000000000000 _mcleanup@GLIBC_2.2.5 + 0
000000201fb0  000400000006 R_X86_64_GLOB_DAT 0000000000000000 __libc_start_main@GLIBC_2.2.5 + 0
000000201fb8  000500000006 R_X86_64_GLOB_DAT 0000000000000000 strcmp@GLIBC_2.2.5 + 0
000000201fc0  000600000006 R_X86_64_GLOB_DAT 0000000000000000 __monstartup@GLIBC_2.2.5 + 0
000000201fc8  000700000006 R_X86_64_GLOB_DAT 0000000000000000 mcount@GLIBC_2.2.5 + 0
000000201fd8  000800000006 R_X86_64_GLOB_DAT 0000000000000000 _Jv_RegisterClasses + 0
000000201fe0  000900000006 R_X86_64_GLOB_DAT 0000000000000000 __cxa_atexit@GLIBC_2.2.5 + 0
000000201fe8  000a00000006 R_X86_64_GLOB_DAT 0000000000000000 atoi@GLIBC_2.2.5 + 0
000000201ff0  000b00000006 R_X86_64_GLOB_DAT 0000000000000000 _ITM_registerTMCloneTa + 0
000000201ff8  000c00000006 R_X86_64_GLOB_DAT 0000000000000000 __cxa_finalize@GLIBC_2.2.5 + 0

honggyukim · 2018-12-07T04:49:24Z

This is related to #119.

namhyung · 2018-12-18T07:22:16Z

Pushed review/libcall-noplt-v5

Changelog:

fix missing result on Ubuntu 17.04 (gcc 6.3)
remove unneeded functions for bind-now

honggyukim · 2018-12-18T08:09:17Z

Thanks for the update. I just tested on Ubuntu 17.04 machine and it works fine now. Thanks!

namhyung added the review label Nov 12, 2018

namhyung closed this as completed in 50a8cae Dec 19, 2018

namhyung added this to the v0.9.2 milestone Jan 15, 2019

namhyung mentioned this issue Jan 16, 2019

v0.9.2 release preparation #643

Closed

mariasfiraiala mentioned this issue Nov 5, 2022

software-stack/libcall-syscall: ltrace doesn't show library calls at all open-education-hub/operating-systems#27

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

tracing library calls even if it has no PLT #592

tracing library calls even if it has no PLT #592

namhyung commented Nov 12, 2018

namhyung commented Nov 16, 2018

honggyukim commented Nov 19, 2018

namhyung commented Nov 20, 2018

namhyung commented Nov 22, 2018

honggyukim commented Nov 22, 2018

namhyung commented Nov 22, 2018

honggyukim commented Nov 22, 2018

namhyung commented Nov 28, 2018

namhyung commented Nov 28, 2018

DanielTimLee commented Dec 4, 2018

honggyukim commented Dec 7, 2018 •

edited

Loading

honggyukim commented Dec 7, 2018

namhyung commented Dec 18, 2018

honggyukim commented Dec 18, 2018

tracing library calls even if it has no PLT #592

tracing library calls even if it has no PLT #592

Comments

namhyung commented Nov 12, 2018

namhyung commented Nov 16, 2018

honggyukim commented Nov 19, 2018

namhyung commented Nov 20, 2018

namhyung commented Nov 22, 2018

honggyukim commented Nov 22, 2018

namhyung commented Nov 22, 2018

honggyukim commented Nov 22, 2018

namhyung commented Nov 28, 2018

namhyung commented Nov 28, 2018

DanielTimLee commented Dec 4, 2018

honggyukim commented Dec 7, 2018 • edited Loading

honggyukim commented Dec 7, 2018

namhyung commented Dec 18, 2018

honggyukim commented Dec 18, 2018

honggyukim commented Dec 7, 2018 •

edited

Loading