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 — 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 — 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.