probing a plt

probing a plt

[Stan Cox]

This is small example showing how a plt may possibly be probed.  The 
implementation is similar to .library in the sense that the plt is 
iterated over and probes added for each plt entry.  Currently the only 
possibility is probing every plt entry in a module.  Suggestions for 
further refinements?

cat 12215.c
main ()
{
   char *abc = "abcdefghijklmnopqrstuvwxyz";
   char *xyz = "zyxwvutsrqpomnlkjihgfedcba";
   int x;
   puts ("a string");
   printf ("length %d %s\n", strlen(abc), abc);
   printf ("length %d %s\n", strlen(xyz), xyz);
   return 0;
}

objdump -d -j .plt 12215.x
12215.x:     file format elf64-x86-64
Disassembly of section .plt:
00000000004003f0 <printf@plt>:
   4003f0:	ff 25 8a 05 20 00    	jmpq   *0x20058a(%rip)        # 600980 
<_GLOBAL_OFFSET_TABLE_+0x18>
   4003f6:	68 00 00 00 00       	pushq  $0x0
   4003fb:	e9 e0 ff ff ff       	jmpq   4003e0 <_init+0x18>
0000000000400400 <puts@plt>:
   400400:	ff 25 82 05 20 00    	jmpq   *0x200582(%rip)        # 600988 
<_GLOBAL_OFFSET_TABLE_+0x20>
   400406:	68 01 00 00 00       	pushq  $0x1
   40040b:	e9 d0 ff ff ff       	jmpq   4003e0 <_init+0x18>
0000000000400410 <__libc_start_main@plt>:
   400410:	ff 25 7a 05 20 00    	jmpq   *0x20057a(%rip)        # 600990 
<_GLOBAL_OFFSET_TABLE_+0x28>
   400416:	68 02 00 00 00       	pushq  $0x2
   40041b:	e9 c0 ff ff ff       	jmpq   4003e0 <_init+0x18>

install/bin/stap --kelf -c ./12215.x -e 'probe process("./12215.x").plt 
{printf ("plt-entry=%s\n",$$name)}' -p2
# probes
process("/work/scox/stap/bugs/12215/12215.x").statement(0x4003f0)? /* 
pc=.absolute+0x4003c8 */ /* <- process("./12215.x").plt? = 
process("./12215.x").statement(4195312)? <- process("./12215.x").plt */
process("/work/scox/stap/bugs/12215/12215.x").statement(0x400400)? /* 
pc=.absolute+0x4003c8 */ /* <- process("./12215.x").plt? = 
process("./12215.x").statement(4195328)? <- process("./12215.x").plt */
process("/work/scox/stap/bugs/12215/12215.x").statement(0x400410)? /* 
pc=.absolute+0x4003c8 */ /* <- process("./12215.x").plt? = 
process("./12215.x").statement(4195344)? <- process("./12215.x").plt */

install/bin/stap --kelf -c ./12215.x -e 'probe process("./12215.x").plt 
{printf ("plt-entry=%s\n",$$name)}'
a string
length 26 abcdefghijklmnopqrstuvwxyz
length 26 zyxwvutsrqpomnlkjihgfedcba
plt-entry=printf
plt-entry=puts
plt-entry=__libc_start_main

(I would expect the __libc_start_main probe to have appeared first and 
the printf probe to have been hit twice, so looking into that.)

Re: probing a plt

[Frank Ch. Eigler]

Stan Cox <scox@redhat.com> writes:

> This is small example showing how a plt may possibly be probed.  

Looks like a good start!

> [...] Currently the only possibility is probing every plt entry in a
> module.  Suggestions for further refinements? [...]
>     probe process("./12215.x").plt {printf ("plt-entry=%s\n",$$name)}

The natural one is to parametrize .plt() with the entry name/wildcard,
which should be available (since you're returning it for $$name).  (It
might also be useful to support .plt(N) for table index N.)

A later step could be to use that name as a heuristic lookup into
libraries that may resolve the same-named function, to find some
possibly-applicable dwarf location data for resolving $context
variables.

- FChE

Re: probing a plt

[Stan Cox]

The unusual behavior was because query_module_symtab, when given an 
address, was returning the address of the containing entry.  Making an 
exception in query_module_symtab for the .plt case now gives predictable 
results:  (this test program dumps out the plt table)

stap --kelf -c "./plt.x plt.x" -e 'probe process("./plt.x").plt 
{printf("plt entry %s\n",$$name)}'
plt entry __libc_start_main
plt entry elf_version
plt entry open
plt entry elf_begin
plt entry elf_kind
plt entry gelf_getehdr
plt entry calloc
plt entry __stpcpy_chk
plt entry dlopen
plt entry __stpcpy_chk
plt entry dlopen
plt entry gelf_getehdr
plt entry dwfl_begin
plt entry dwfl_report_offline
plt entry dwfl_report_end
plt entry dwfl_module_getelf
plt entry elf_getshstrndx
plt entry gelf_getphdr
plt entry gelf_getphdr
plt entry gelf_getphdr
plt entry elf_rawfile
plt entry printf
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_strptr
plt entry elf_nextscn
plt entry gelf_getshdr
plt entry elf_getdata
plt entry elf_scnshndx
plt entry elf_getshstrndx
plt entry gelf_getrela
plt entry gelf_getsymshndx
plt entry elf_getscn
plt entry gelf_getshdr
plt entry dwfl_module_relocate_address
plt entry dwfl_standard_find_debuginfo
...

Re: probing a plt

[Stan Cox]

On 09/02/2011 02:35 PM, Stan Cox wrote:
> I would expect the __libc_start_main probe to have appeared first and
> the printf probe to have been hit twice

I'm seeing this puzzling behavior for this simple program:
   char *abc = "abcdefghijklmnopqrstuvwxyz";
   char *xyz = "zyxwvutsrqpomnlkjihgfedcba";
   int x;
   struct timeval tp;
   struct timezone tzp;
   gettimeofday (&tp, &tzp);
   printf ("length %d %s %d%d\n", strlen(abc), abc, tp.tv_sec, tp.tv_usec);
   printf ("length %d %s\n", strlen(xyz), xyz);
   puts ("a string");
   return 0;
If I set a break at every callsite for a function in the plt and at the 
plt entry then gdb does what I expect; I get matching "plt ref" 
(callsite) and "plt entry" (foo@plt entry)
GDB:
plt ref __libc_start_main @400494 rip=0x400494
plt entry __libc_start_main @0000000000400460 rip=0x400460
plt entry  @0000000000400420 rip=0x400420
plt ref gettimeofday @400580 rip=0x400580
plt entry gettimeofday @0000000000400450 rip=0x400450
plt entry  @0000000000400420 rip=0x400420
plt ref printf @4005cd rip=0x4005cd
plt entry printf @0000000000400430 rip=0x400430
plt entry  @0000000000400420 rip=0x400420
length 26 abcdefghijklmnopqrstuvwxyz 1315342376852950
plt ref printf @40060f rip=0x40060f
plt entry printf @0000000000400430 rip=0x400430
length 26 zyxwvutsrqpomnlkjihgfedcba
plt ref puts @40061b rip=0x40061b
plt entry puts @0000000000400440 rip=0x400440
plt entry  @0000000000400420 rip=0x400420
a string

However stap gives output in an unusual order and the printf plt entry 
is only hit once.  (The gdb breakpoints and awk probes are automatically 
generated with an awk script and are thus equivalent)
length 26 abcdefghijklmnopqrstuvwxyz 1315342362875422
length 26 zyxwvutsrqpomnlkjihgfedcba
a string
STAP:
plt ref __libc_start_main @400494 rip=0x400470
plt entry  @0000000000400420 rip=0x400408
plt entry printf @0000000000400430 rip=0x400408
plt entry puts @0000000000400440 rip=0x400408
plt entry gettimeofday @0000000000400450 rip=0x400408
plt entry __libc_start_main @0000000000400460 rip=0x400408
plt ref gettimeofday @400580 rip=0x400554
plt ref printf @4005cd rip=0x400554
plt ref printf @40060f rip=0x400554
plt ref puts @40061b rip=0x400554

Re: probing a plt

[Mark Wielaard]

Hi Stan,

On Tue, 2011-09-06 at 18:02 -0400, Stan Cox wrote:
> On 09/02/2011 02:35 PM, Stan Cox wrote:
> > I would expect the __libc_start_main probe to have appeared first and
> > the printf probe to have been hit twice
> 
> I'm seeing this puzzling behavior for this simple program:
>    char *abc = "abcdefghijklmnopqrstuvwxyz";
>    char *xyz = "zyxwvutsrqpomnlkjihgfedcba";
>    int x;
>    struct timeval tp;
>    struct timezone tzp;
>    gettimeofday (&tp, &tzp);
>    printf ("length %d %s %d%d\n", strlen(abc), abc, tp.tv_sec, tp.tv_usec);
>    printf ("length %d %s\n", strlen(xyz), xyz);
>    puts ("a string");
>    return 0;

I am assuming this is wrapped in a main() function and compiled with gcc
with which flags? Could you maybe just attach the actual source file and
post the gcc command line to build it? Which architecture is this?

> If I set a break at every callsite for a function in the plt and at the 
> plt entry then gdb does what I expect; I get matching "plt ref" 
> (callsite) and "plt entry" (foo@plt entry)
> GDB:
> plt ref __libc_start_main @400494 rip=0x400494
> plt entry __libc_start_main @0000000000400460 rip=0x400460
> plt entry  @0000000000400420 rip=0x400420
> plt ref gettimeofday @400580 rip=0x400580
> plt entry gettimeofday @0000000000400450 rip=0x400450
> plt entry  @0000000000400420 rip=0x400420
> plt ref printf @4005cd rip=0x4005cd
> plt entry printf @0000000000400430 rip=0x400430
> plt entry  @0000000000400420 rip=0x400420
> length 26 abcdefghijklmnopqrstuvwxyz 1315342376852950
> plt ref printf @40060f rip=0x40060f
> plt entry printf @0000000000400430 rip=0x400430
> length 26 zyxwvutsrqpomnlkjihgfedcba
> plt ref puts @40061b rip=0x40061b
> plt entry puts @0000000000400440 rip=0x400440
> plt entry  @0000000000400420 rip=0x400420
> a string
> 
> However stap gives output in an unusual order and the printf plt entry 
> is only hit once.  (The gdb breakpoints and awk probes are automatically 
> generated with an awk script and are thus equivalent)

Could you post the awk script and the exact way you invoke gdb and stap?

> length 26 abcdefghijklmnopqrstuvwxyz 1315342362875422
> length 26 zyxwvutsrqpomnlkjihgfedcba
> a string
> STAP:
> plt ref __libc_start_main @400494 rip=0x400470
> plt entry  @0000000000400420 rip=0x400408
> plt entry printf @0000000000400430 rip=0x400408
> plt entry puts @0000000000400440 rip=0x400408
> plt entry gettimeofday @0000000000400450 rip=0x400408
> plt entry __libc_start_main @0000000000400460 rip=0x400408
> plt ref gettimeofday @400580 rip=0x400554
> plt ref printf @4005cd rip=0x400554
> plt ref printf @40060f rip=0x400554
> plt ref puts @40061b rip=0x400554

Thanks,

Mark

Re: probing a plt

[Stan Cox]

[-- Attachment #1: Type: text/plain, Size: 62 bytes --]

This should show the behavior:
  12215.sh stap
  12215.sh gdb

[-- Attachment #2: 12215.c --]
[-- Type: text/x-csrc, Size: 398 bytes --]

#include <stdio.h>
#include <string.h>
#include <sys/time.h>

main ()
{
  char *abc = "abcdefghijklmnopqrstuvwxyz";
  char *xyz = "zyxwvutsrqpomnlkjihgfedcba";
  int x;
  struct timeval tp;
  struct timezone tzp;
  gettimeofday (&tp, &tzp);
  printf ("length %d %s %d%d\n", strlen(abc), abc, tp.tv_sec, tp.tv_usec);
  printf ("length %d %s\n", strlen(xyz), xyz);
  puts ("a string");
  return 0;
}

[-- Attachment #3: 12215.sh --]
[-- Type: application/x-shellscript, Size: 1421 bytes --]

Re: probing a plt

[Mark Wielaard]

On Wed, 2011-09-07 at 12:15 -0400, Stan Cox wrote:
> This should show the behavior:
>   12215.sh stap
>   12215.sh gdb

Yes, I am seeing the same behavior, but don't really understand why.

BTW. You can make the scripts architecture independent (I was using it
on a i686) by using uaddr() in the stap script and $pc in the gdb
command instead of "rip".

Cheers,

Mark