When production software fails, it’s critically important to both understand why it failed and prevent it from happening again. From the largest incidents to the “wish” priority bugs, root cause analysis remains a tested strategy for fixing software defects. This usually involves checking logs, metrics, reading the code, and running local simulations. But what do you do when you have a failure that evades all attempts to understand it? We were facing just that scenario at HOAi.
One of our critical applications was failing its health checks intermittently, requiring an automatic restart. We sent in engineers and AI agents to investigate the issue. The hypotheses generally amounted to claims that the app was running some rare resource intensive activity, pointing to its final log messages as the culprits. We applied performance fixes, tweaks, the whole bucket. It kept failing. We turned to performing a complete root cause analysis - what exactly was this process doing in its final moments? We dove into Node.js internals to find out.
Node event loop
Node.js runs programs in a continuous loop of “events” to implement asynchronous execution. Its behaviour is well documented, so I will be brief. Programs are broken into segments of continuous execution, also known as “callbacks” or “events”. Segments start by being created by another segment, and stop by handing off their result to a segment that is waiting on it. Node programs start with a single entry segment and terminate gracefully when there are no more to run.
When we investigated our failing containers, we saw plain indicators of event loop issues: CPU was pegged at 100% on only one core, no network traffic, and no log activity. There was likely a part of our code that was hogging the event loop with a long-running single segment, or a large number of “microtask” events that get processed on the same phase. We set out to locate the code responsible.
Detection by tracing
To determine where the bug was, we needed a tool that automatically captured what was running in our application. We were unable to reproduce the issue locally, and we had no way to predict when it would happen on a production container. We needed an approach that was hands-off and production ready.
Our first approach was an event loop block detector in the code of the application itself. We were inspired by Ashby’s blog post Detecting Node Event Loop Blockers. It tackles this challenge by combining the event loop with generally-available software tracing products, emitting visible spans whenever the loop was blocked. We re-implemented their strategy and deployed it, and eagerly waited for results to come in.
However, our reports blamed only a small number of inefficient functions that could not possibly account for the instability we saw. These blocks would last less than 5 seconds on average, not the minutes needed to trigger a container restart. We fixed them despite our doubts, but our doubts were confirmed when that did not fix our problem.
We then had an aha moment - what if the problematic code never yielded back to the event loop? With tracing-based detection, code would need to complete its segment so the tracer could finish its span and report it. If it was a single segment that looped infinitely, it would never self-report. We decided to approach the problem from an entirely different angle.
Detection by crash reports
Our new idea was to utilize Node’s built-in debugger tool to create a CPU profile of the Node process in its final moments. The debugger can attach to any running Node process, even one that is stuck in an infinite loop. We were interested in its profile command, which samples the program’s running stack and records which functions were in the stack at each sample.
We added a new container entrypoint to manage process signals and call a profiler script. The entrypoint watched for termination or interrupt signals from our container platform. At that point in each container’s lifecycle, its health checks were already failing, and our load balancer already removed it from the target pool. It was at the right moment when the looping code was sure to be running, and everything else was quiet.
# entrypoint.sh
node main.mjs &
NODE_PID="$!"
terminate() {
/crash-report.sh "$NODE_PID"
kill -TERM "$NODE_PID" 2>/dev/null
}
trap terminate TERM INTThe profiler script was an expect-based wrapper around the Node debugger to start and stop the profiler. The profile only had to run for 5 seconds. Once done, the script uploaded the results to an AWS S3 bucket and the entrypoint killed the main process.
# crash-report.sh
expect <<EOF
set timeout 30
spawn node inspect -p $NODE_PID
expect "debug>"
send "profile\r"
expect "debug>"
sleep 5
send "profileEnd\r"
expect "debug>"
send "profiles\[0\].save()\r"
expect "debug>"
send ".exit\r"
expect eof
EOF
aws s3 cp node.cpuprofile "s3://${CRASH_REPORTS_BUCKET}/$(date -u +%Y-%m-%dT%H-%M-%SZ)-$(hostname)/node.cpuprofile"Once we deployed our new strategy, we saw results within the hour from newly crashed containers. We viewed the crash reports in freely available flame graph visualization tools, and quickly located the problem code. The final root cause after all of this investigation? Calling indexOf(str, N) on an empty string.
Future resilience
We kept the crash-reporting entrypoint in production since it caused no performance loss. Rather than running it 24/7 with Node’s —prof option, we ran the profiler only when a container was about to exit anyway due to being unhealthy. The only functions risked were the guilty code still blocking the event loop.
Our detection tool has since found two more unique bugs that would have cost us days to solve. Instead, we spent one hour each checking the crash reports and fixing the reported functions.
We have open-sourced a demonstration version of our tool to Github that you can try out today with just Docker and curl.