strace (Syscall Tracing)
debugging a process that refuses to explain itself
Developer toolingdeveloper tooling / debugging
The symptom
Your API container is "healthy" but the first request after a deploy takes 32 seconds. Logs show:
12:04:01 starting server
12:04:33 listening on :8080
Thirty-two seconds of nothing. CPU is at 2%. Adding print statements changes nothing — the gap is inside a library you don't own.
Reasoning it out
CPU idle + wall time burning = the process is BLOCKED, not computing. A profiler won't help you here; sampling a sleeping thread just shows "waiting". You don't need to know what your code is doing — you need to know what it's asking the kernel for.
Every block (file, socket, DNS, lock) is a syscall. So ask the kernel:
strace -f -tt -T -p $(pgrep -f myserver)
-f follow forked/cloned threads (miss this and you trace nothing)
-tt wall-clock timestamp per line
-T time SPENT INSIDE each syscall — the money column
The reveal
12:04:03.114 connect(7, {AF_INET, 10.0.0.53:53}, 16) = 0 <0.000041>
12:04:03.114 sendto(7, "\3api\7internal"...) = 41 <0.000038>
12:04:08.115 poll([{fd=7, POLLIN}], 1, 5000) = 0 (Timeout) <5.000912>
... repeated ...
Not slow code. DNS. A nameserver that black-holes packets, 5s timeout × attempts × ndots-driven retries. Fix is in /etc/resolv.conf (options timeout:1 attempts:2 ndots:1), not in your app.
The mental model
strace shows exactly one thing: the boundary between your process and the kernel. That boundary is where all waiting happens — so a gap you can see in strace is I/O, and a gap you CAN'T see is userspace CPU (tight loop, JSON parsing, regex backtracking). That's the split that tells you which tool to reach for next.
The three invocations worth memorizing
- What is it waiting on right now?
strace -f -tt -T -p PID
- Where did it look for that config/lib? (the classic "works locally" bug)
strace -f -e trace=openat ./app 2>&1 | grep ENOENT
- Which syscalls dominate? (summary, not firehose)
strace -f -c -p PID # then Ctrl-C
Gotchas people hit
- ptrace makes syscalls ~10–100× slower. Never attach to a hot prod process without -e filtering, and prefer -c. On a busy box, reach for perf/bpftrace instead.
- In Docker you need: --cap-add=SYS_PTRACE (or --privileged). Attaching to another user's process may need /proc/sys/kernel/yama/ptrace_scope=0.
- Silence in strace ≠ nothing happening. It means userspace work — go to a profiler.
- -s 128 to stop strings being truncated at 32 chars; you'll want the full path/query.
- macOS: no strace. Use dtruss/ktrace (SIP makes it painful) or run it in a Linux container.
Your exercise
Run this and read the number:
strace -f -c -e trace=openat python3 -c "import requests" 2>&1 | tail -5
strace -f -e trace=openat python3 -c "import requests" 2>&1 | grep -c ENOENT
The ENOENT count is how many files Python looked for and did NOT find while resolving imports — every sys.path entry × every candidate name. On a typical box it's a few hundred.
Question back to me: given that number, why does adding one more directory to sys.path (or one more layer of site-packages in a container image) measurably slow cold starts — and what does that suggest about deep import trees in a serverless function?