Find out which syscall is actually eating your latency with one dtrace one-liner

Somebody asked me last week why their service’s p99 was ugly when average latency looked fine, and their instinct was to reach for strace -T. I get why: -T gives you per-syscall timing, it feels like the right tool. It’s the wrong tool for this specific job, and I want to explain why before I give you the thing that actually works.

Why strace -T lies to you here

strace attaches via ptrace(2), which stops the traced process at every syscall entry and exit so the tracer can inspect it. That stop-the-world behavior is itself latency you’re injecting into the exact thing you’re trying to measure. Your p99 under strace is not your p99 in production. It’s your p99 plus ptrace overhead, and that overhead isn’t uniform across syscall types, so you can’t even reliably subtract it back out. You’re debugging a system you’ve already changed by observing it.

What actually works: aggregate in-kernel, don’t stop the process

DTrace (illumos/FreeBSD/macOS) and bpftrace (Linux, via eBPF) both let you attach probes to syscall entry/return and aggregate timing inside the kernel, without stopping the traced process at each call. The process keeps running at full speed; you’re sampling, not gating.

On FreeBSD, this is the one-liner I actually run first on anything with unexplained tail latency:

dtrace -n '
syscall:::entry /pid == $target/ { self->ts = timestamp; }
syscall:::return /pid == $target/ { @[probefunc] = quantize(timestamp - self->ts); self->ts = 0; }
' -p <pid>

That gives you a latency histogram per syscall name, in nanoseconds, for one specific PID, with no meaningful observer effect. Let it run through a few slow requests and Ctrl-C it, and the quantize() output shows you the actual distribution, not just an average, which is the whole point when you’re chasing a tail.

The Linux equivalent

Same idea via bpftrace, since that’s what you’ve got if you’re not on BSD:

bpftrace -e '
tracepoint:raw_syscalls:sys_enter /pid == $1/ { @start[tid] = nsecs; }
tracepoint:raw_syscalls:sys_exit /pid == $1/ {
  @ns[args->id] = hist(nsecs - @start[tid]);
  delete(@start[tid]);
}
' <pid>

You’ll get syscall numbers instead of names out of the box, so cross-reference against /usr/include/asm/unistd_64.h for your arch, or resolve them with ausyscall <num> if you have audit tools installed.

What you’re looking for

Nine times out of ten when someone brings me a “fine on average, ugly at p99” latency problem, the histogram shows a bimodal distribution on one specific syscall, usually something doing I/O (read, pwrite64, futex if it’s lock contention, epoll_wait if it’s an event-loop stall). A clean unimodal spread across everything means your problem probably isn’t syscall-level at all. Go look at GC pauses or scheduler latency instead, and save yourself the trip down this road.

The broader point, since I know somebody’s going to ask “why not just use $APM_TOOL”: application performance monitoring agents are themselves doing instrumentation, often via similar hooking mechanisms, and they cost real overhead too, just distributed differently than ptrace. There is no free lunch in observability. There’s only observability with overhead you’ve characterized versus overhead you haven’t. dtrace/bpftrace get you closer to “characterized” than almost anything else available, which is why they’ve earned a permanent spot in my toolkit instead of a “trendy new tool” slot that rotates out every two years.