Syscall tracing very very very slow

[Timmmm]

On current master, the following command takes a very long time:

❯ time cargo run --release --example syscalls -- ls
    Finished release [optimized] target(s) in 0.01s
     Running `target/release/examples/syscalls ls`
pid = 60232, pc = 7f33dc5e0c50: [execve], SyscallExit
pid = 60232, pc = 7f33dc5e5ccb: [brk], SyscallEnter
pid = 60232, pc = 7f33dc5e5ccb: [brk], SyscallExit
...
pid = 60232, pc = 7f33dbec4b06: Exiting { exit_code: 0 }

real    0m43.973s
user    0m0.054s
sys 0m0.049s

strace ls only takes 17 ms. Any idea what the difference is? I was under the impression that strace uses ptrace in the same way to Pete. So how is it 2500x faster?

[konkitoman]

First i don't know this project, i was looking at it and i seen your issue!

In src/ptracer.rs at 363 is:

const DEFAULT_POLL_DELAY: Duration = Duration::from_millis(100);

You can add this line after 36 in examples/syscalls.rs

*ptracer.poll_delay_mut() = std::time::Duration::ZERO;

The delay i think was added to be more readable!

[Timmmm]

Interesting. Surely there's a way to do this without polling?

Also btw @ranweiler you can slightly simplify the loop that does the poll because in Rust loops can return values.

[ranweiler]

@Timmmm, thanks for reporting, the default poll delay is definitely too high. I'll try to at least push a perf bugfix for that tonight, but as noted above, you can set it yourself in the meantime.

I'm experimenting with a few different strategies that would let the kernel notify us, instead of manual polling. There are some tradeoffs, assumptions about tracee behavior, and version-dependent Linux-isms at play here, so I'm trying to be very careful in how I implement it. I'll probably preserve the polling as a fallback mode, but that's part of what I'm trying to sort out. Please stand by!