Worshipping at the altar of Brendan Gregg

Rewind added a `rewind time` command to its deterministic VM that reports a program's critical path alongside elapsed time, showing that a libuv 1.51.0 build and test run took 78.0 seconds on the VM's one CPU but has a critical path of 47.4 seconds, meaning no amount of parallelism can shorten it below that. The command applies Brendan Gregg's thread state analysis and off-CPU analysis, reporting that the run was 67% asleep (23.1 s in epoll_pwait, 8.53 s in clock_nanosleep, 100 ms in futex) and 33% computing, so a CPU profile would miss most of the wait time. Rewind logs every context switch, which the author says makes off-CPU analysis practical without the tracing overhead and noise of live-machine profiling.

Okay, I am the first to admit that I’m a bit manic with AI. When you are working on a problem that has endless possibilities, it is difficult to constrain yourself to a limited set of features. Can I just add one more? I have been amazed at all the fun and useful things that a deterministic VM like Rewind https://rewindvm.dev enables. I have been using it to help find heisenbugs https://fzakaria.com/2026/10/03/rewind-vm-a-flaky-build-you-only-catch-once , to make profile-guided optimization reproducible https://fzakaria.com/2026/11/07/making-profile-guided-optimization-reproducible , and to make Nix builds bit-reproducible https://fzakaria.com/2026/11/09/what-if-every-nix-build-were-bit-reproducible . But the most fun has been using it to understand performance. Turns out that performance is yet another area where Rewind shines. I have been using it to analyze the critical path of builds. What is the critical path? The critical path is the longest chain of dependent work in a program. It is the minimum time that the program can take to complete, regardless of how many resources you throw at it. The only way to make a program faster is to shorten the critical path. If you worship at the altar of Brendan Gregg, you know he spent years turning performance analysis from a dark art into a science. This is a small offering to him. 🤲 I added a new rewind time command to Rewind that analyzes a recording and tells you where the time went and what would make the run finish sooner. You can drill into any part of that answer and see the source lines responsible for it. It’s like Brendan Gregg’s flame graphs https://www.brendangregg.com/flamegraphs.html but ~~on steroids~~ for the critical path and with a debugger attached.<sup 1</sup 1All the ideas for the command are either inspired by or directly influenced by Brendan Gregg’s work https://www.brendangregg.com/ . Kneel before Zod Aside: New to Rewind? Start with a flaky build you only catch once https://fzakaria.com/2026/10/03/rewind-vm-a-flaky-build-you-only-catch-once and dafuq is a deterministic VM? https://fzakaria.com/2026/10/24/dafuq-is-a-deterministic-vm Let’s see how it works by analyzing the critical path of a libuv https://github.com/libuv/libuv build and test run. The build and test suite takes 78 seconds inside Rewind, and even with 64 cores it still takes 47 seconds. Why? The usual answer is to look at a CPU profile, and in this case a CPU profile would be almost useless. For two thirds of those 47 seconds, the work the build is waiting on is not computing at all: it is asleep . 💤💤💤 § where-the-time-goes Where the time goes Every rewind time starts with two numbers: bash $ rewind time 7a29e716 libuv-1.51.0 78.0 s elapsed on the VM's one CPU 47.4 s critical path: the least it can take on any number of CPUs 67% asleep epoll pwait 23.1 s, clock nanosleep 8.53 s, futex 100 ms , 33% computing The first is how long the run took on the VM’s one virtual CPU. The second is the critical path : the longest chain of work where each step had to wait for the one before. No number of CPUs makes a run shorter than its critical path, so the gap between the two numbers is all that parallelism can buy you. The line under the two numbers applies Gregg’s thread state analysis https://www.brendangregg.com/tsamethod.html . Here the biggest state is asleep: 23 seconds in epoll pwait and 8.5 in clock nanosleep . A sleeping thread is invisible to a CPU profiler. Gregg’s answer is off-CPU analysis https://www.brendangregg.com/offcpuanalysis.html : look at where threads block, not only where they compute. On a live machine, off-CPU analysis is hard. Linux can trace which thread woke which, and Gregg built wakeup and off-wake profiling https://www.brendangregg.com/blog/2016-02-01/linux-wakeup-offwake-profiling.html on top of that, but you have to be tracing before the slow run happens, the tracing has a cost, and most of the sleeps you capture are noise. Rewind already logs every context switch because it needs them to replay, and now it records every wakeup and who caused it too. All that juicy information is in every recording. 🤤 Here is the whole output for libuv: bash $ rewind time 7a29e716 libuv-1.51.0 78.0 s elapsed on the VM's one CPU 47.4 s critical path: the least it can take on any number of CPUs 67% asleep epoll pwait 23.1 s, clock nanosleep 8.53 s, futex 100 ms , 33% computing The critical path by phase 3.54 s configurePhase ██ 1.67 s buildPhase █ 42.0 s checkPhase █████████████████████ 99 ms 5 other phases The critical path by process on path pid process, with what it started 47.4 s 34 init › bash -e source-stdenv.sh default-builder.sh 41.9 s 4076 ├─ make -j8 SHELL=bash-5.3p3/bin/bash VERBOSE=y check 36.4 s 4910 │ ├─ make › bash › lt-run-tests 3.38 s 5412 │ │ ├─ lt-run-tests hrtime hrtime asleep in clock nanosleep 3.38 s 2.00 s 5013 │ │ ├─ lt-run-tests delayed accept delayed accept asleep in epoll pwait 2.00 s 1.62 s 5126 │ │ ├─ lt-run-tests fs event watch dir fs event watch dir asleep in epoll pwait 1.62 s 1.60 s 5103 │ │ ├─ lt-run-tests fs event close in callback fs event close in… asleep in epoll pwait 1.60 s 1.60 s 5508 │ │ ├─ lt-run-tests metrics idle time metrics idle time asleep in epoll pwait 1.00 s, computing 600 ms 1.24 s 6095 │ │ ├─ lt-run-tests tcp write ready tcp write ready 1.14 s 5510 │ │ ├─ lt-run-tests metrics idle time thread metrics idle time t… asleep in epoll pwait 1.00 s 1.10 s 5132 │ │ ├─ lt-run-tests fs event watch file current dir fs event wat… asleep in epoll pwait 1.10 s 22.6 s │ │ └─ 279 more 5.59 s 4077 │ └─ make test/run-tests 2.22 s 4183 │ ├─ gcc -fPIC -fstack-clash-protection -O2 -U FORTIFY SOURCE … 2.10 s 4189 │ │ └─ cc1 /build/source/test/test-fs.c 3.35 s │ └─ 20 more 1.99 s 68 ├─ sh ./autogen.sh 1.99 s │ └─ 9 more 1.67 s 2642 ├─ make -j8 SHELL=bash-5.3p3/bin/bash 1.67 s │ └─ 5 more 1.53 s 403 └─ bash ./configure --disable-static --disable-dependency-tracking… 1.47 s └─ 581 more What would shorten it sooner pid if this took no time 36.1 s every lt-run-tests, 600 processes 6.66 s every cc1, 283 processes 3.38 s 5412 75 sleeps in clock nanosleep: lt-run-tests hrtime hrtime 2.00 s 5013 2 sleeps in epoll pwait: lt-run-tests delayed accept delayed accept 1.76 s 4189 cc1 /build/source/test/test-fs.c 1.62 s 5126 30 sleeps in epoll pwait: lt-run-tests fs event watch dir fs event watc… 1.60 s 5103 16 sleeps in epoll pwait: lt-run-tests fs event close in callback fs ev… 1.60 s 5508 lt-run-tests metrics idle time metrics idle time 1.22 s every perl, 9 processes 1.14 s 5510 lt-run-tests metrics idle time thread metrics idle time thread Look closer rewind time 7a29e716 --in PID one process: its threads, sleeps and waits rewind time 7a29e716 --folded the path for flamegraph.pl or speedscope.app rewind time 7a29e716 --perfetto F every process on a timeline, for ui.perfetto.dev The second table is the path as a tree of processes based on Gregg’s colony graph https://www.brendangregg.com/ColonyGraphs/execution.html idea. Each line is a process with everything it started, and its time on the critical path.<sup 2</sup 2A ps snapshot might miss short-lived process invocations; the recording has every fork, regardless of how brief. In this build, make check needs 41.9 of the total 47.4 seconds, and 36.4 of that is lt-run-tests , libuv’s test runner. The test runner invokes 287 tests each spending 1-3 seconds. All of those tests are on the path, and the path is a single chain, so the runner ran them one after another. Worse, most of each test is spent asleep, waiting on timers. Drag can be less than time on the path. The last table answers a different question: how much sooner would the run finish if this part took no time? The critical path method calls this drag . For the truly magical part, we can jump to any part of the path and see what was happening, invoke gdb and fork the run at that moment. A profiler hands you a stack, sampled at some moment you can never go back to. Every frame in rewind time is a moment in a recording, and Rewind can replay the run to it. --in looks inside one process,<sup 3</sup 3It can take a pid, a program or a word of the command line. so let’s dive into the hrtime test that spent 3.38 seconds asleep in clock nanosleep : bash $ rewind time 7a29e716 --in hrtime lt-run-tests hrtime hrtime pid 5412 3.38 s on the critical path with what it started, 7% of the 47.4 s path 100% asleep clock nanosleep 3.38 s , <1% computing What would shorten it sooner pid if this took no time 3.38 s 75 sleeps in clock nanosleep Look closer rewind where 7a29e716 115894 --pid 5412 the source line the first row's time starts at rewind time 7a29e716 --perfetto F every process on a timeline Since this test spent 100% of its time asleep, the step provided on the last line is where it began. rewind where replays the run to that step and asks gdb where the thread was: bash $ rewind where 7a29e716 115894 --pid 5412 process 5412 lt-run-tests , thread 5412, at step 115894 2 uv sleep src/unix/core.c:1869 1867 1868 do 1869 rc = nanosleep &timeout, &timeout ; 1870 while rc == -1 && errno == EINTR ; 1871 arguments: msec = 45 locals: timeout = {tv sec = 0, tv nsec = 45000000} rc = <optimized out PRETTY FUNCTION = <error: Cannot access memory at address 0x7fb172519ae8 called from 3 run test hrtime test/test-hrtime.c:39 called from 4 libc start call main ../sysdeps/nptl/libc start call main.h:58 🎯 We can see that the test is calling uv sleep 45 from line 39 of test/test-hrtime.c , and that it is sleeping for 45 milliseconds. It does that 75 times for a total of 3.38 seconds.<sup 4</sup 4Turns out that the test sleeps on purpose: it is checking how far uv hrtime moves across a sleep. There is nothing to optimize in this case. As the cherry on top: the run is deterministic, so step 115,894 is the same instruction every time you replay it. You can open rewind gdb at that step and investigate to your heart’s content. The Rewind app’s Time tab shows the same answers. The path becomes a flame graph, colored the way Gregg colors his off-CPU flame graphs https://www.brendangregg.com/FlameGraphs/offcpuflamegraphs.html : computing is warm, asleep is blue, and a process shades from one to the other by how much of its time it slept. Clicking a frame picks it and moves the playhead there, so the build log, the process tree and the files all show that moment; clicking a process again zooms into it. When you pick a blue frame, the app replays the run to that part’s longest sleep and shows the stack where it slept: Under the stack, Show source opens the source panel at that moment on that thread, and Open gdb here opens gdb in a fork of the run at the sleep: If you’d rather use tools you already know, rewind time can emit the data in their formats: folded stacks for flamegraph.pl https://github.com/brendangregg/FlameGraph and speedscope https://www.speedscope.app , or a Perfetto trace for ui.perfetto.dev https://ui.perfetto.dev . The flame graph below is the real flamegraph.pl output: click a frame to zoom in, or open it on its own https://fzakaria.com/assets/images/rewind-time-libuv-flamegraph.svg . § kneeling-at-the-altar Kneeling at the altar Every idea here predates Rewind. Gregg has been drawing off-CPU and wakeup flame graphs for over a decade, and build systems have reported critical path information potentially even longer.<sup 5</sup 5 Bazel’s critical path analysis https://bazel.build/advanced/performance/build-performance-metrics is a great example of this, and it has been around for years. I have been inspired by his work since I first dabbled in eBPF https://ebpf.io/ , back when flame graphs https://www.brendangregg.com/flamegraphs.html were new. 🙇 What Rewind adds is the data. Lots of it. Rewind has that data because it can’t replay without it. On a single CPU the only thing that changes from run to run is the scheduler, so every recording already logs every context switch. This changes the economics of performance analysis. On a live machine, you have to trace before the run, and tracing has a cost. You can only trace a few runs, and you have to pick which ones. Rewind traces every run, so you can analyze any of them later, and do so exactly. It has just been a ~~manic fever~~ joy to take ideas I have admired for years, point them at a deterministic VM, and watch them work in ways that are hard or impossible on a normal machine. Please accept rewind time as my offering at the altar of Brendan Gregg.