[Bug dyninst/23511] New: Weird slowness in the dyninst runtime when tracing simplest C programs

["agentzh at gmail dot com" <sourceware-bugzilla at sourceware dot org>]

https://sourceware.org/bugzilla/show_bug.cgi?id=23511

            Bug ID: 23511
           Summary: Weird slowness in the dyninst runtime when tracing
                    simplest C programs
           Product: systemtap
           Version: unspecified
            Status: UNCONFIRMED
          Severity: normal
          Priority: P2
         Component: dyninst
          Assignee: systemtap at sourceware dot org
          Reporter: agentzh at gmail dot com
  Target Milestone: ---

Consider the simplest C program below:

```C
int main(void) {
    return 0;
}
```

And then probing the `main()` function with the dyninst runtime would take more
than 3 sec on my fast MBP machine:

```
$ time stap -e 'probe begin { println("hello") exit() }' -c ./a.out -v
--dyninst
Pass 1: parsed user script and 52 library scripts using
163204virt/10072res/7120shr/3216data kb, in 30usr/0sys/35real ms.
Pass 2: analyzed script: 1 probe, 1 function, 0 embeds, 0 globals using
163204virt/10072res/7120shr/3216data kb, in 0usr/0sys/0real ms.
Pass 3: using cached
/home/agentzh/.systemtap/cache/36/stap_3697a0afe348f5225015cad94941fe91_1087.c
Pass 4: using cached
/home/agentzh/.systemtap/cache/36/stap_3697a0afe348f5225015cad94941fe91_1087.so
Pass 5: starting run.
hello
Pass 5: run completed in 3120usr/90sys/3225real ms.

real    0m3.269s
user    0m3.158s
sys     0m0.104s
```

Even when the compiled `.so` file is hitting the cache!

Most of the time is spent on Pass 5 (3225ms).

I'm using the latest master branch of systemtap on Fedora 27 x86_64 (kernel
4.16.16).

If I understand it correctly, dyninst uses ptrace() to probe the target
process, just like GDB. But GDB works much faster in batch mode probing the
same C program:

```
$ time gdb -batch -ex 'b main' -ex r -ex c --args ./a.out
Breakpoint 1 at 0x40048b: file a.c, line 2.

Breakpoint 1, main () at a.c:2
2       #define mref(r, t)  ((t *)(void *)(uintptr_t)(r).ptr32)
[Inferior 1 (process 22157) exited normally]

Press ENTER or type command to continue
Breakpoint 1 at 0x40048b: file a.c, line 2.

Breakpoint 1, main () at a.c:2
2       #define mref(r, t)  ((t *)(void *)(uintptr_t)(r).ptr32)
[Inferior 1 (process 22177) exited normally]

real    0m0.206s
user    0m0.175s
sys     0m0.046s
```

Only 206ms is needed. My hunch is that stap dyninst should be even faster than
GDB since it looks more light weight.

Is it a known issue? Any easy fix or workaround here? Thanks!

-- 
You are receiving this mail because:
You are the assignee for the bug.