A Heartbeat for the Main Thread

If you can’t measure it, you can’t fix it.

The sidebar was slow. Not always. Not predictably. During large scans, with duplicate detection running, the sidebar would stutter. Scrolling felt wrong. Selections lagged. The app was doing things, but the UI was not keeping up.

“Slow” is not a bug report. You cannot fix “slow.” You can fix “main thread blocked for 340ms every time a duplicate hash resolves.”

PerfLogWriter was the first thing I built to address this. Not a fix: a measurement tool.

It is a simple file-based logger. Events are written to disk with timestamps and categories. Log files rotate when they reach a size limit, so the logs do not grow unbounded over a long session. Structured entries, one per line, parseable by the analysis scripts in Scripts/Performance/.

The key addition was a heartbeat.

A DispatchQueue.main repeating timer fires every 1.5 seconds. Each time it fires, it records how long it actually waited. On an uncontested main thread, the timer fires close to on time. When the main thread is blocked, the timer fires late. The difference between the scheduled interval and the actual interval is the stall duration.

The log entry looks like this:

2024-xx-xx 14:32:17.842 [MAIN_THREAD_BLOCKED] 340ms

If that line is not in the log, the main thread was not blocked. If it is, you know exactly when and for how long. This turns a vague feeling into a specific event with a timestamp.

Click “Start background work” to simulate a main thread block. The heartbeat timer detects the delay and logs it.

The logs pointed straight at the cause.

Duplicate detection runs a TaskGroup with six workers. Each worker hashes a file, computes a digest, and reports a result. Six workers producing results as fast as NVMe can feed them. The original implementation called back into the ViewModel for each result:

// Bad: per-result mutation triggers O(N) SwiftUI diffs
for await result in group {
    self.cleanupResult = result  // triggers re-render every time
}

With thousands of duplicate candidates, this meant thousands of forced main-thread hops. Each one was small. But they arrived so fast that SwiftUI was running a full view diff after every single assignment, and the main thread never got a quiet moment to do its actual job.

The fix is batching:

// Good: batch updates every 250ms
var buffer: [Result] = []
let flushTimer = Timer.scheduledTimer(withTimeInterval: 0.25, repeats: true) { _ in
    Task { @MainActor in
        self.results.append(contentsOf: buffer)
        buffer.removeAll()
    }
}
for await result in group {
    buffer.append(result)
}

Instead of updating state per result, accumulate results in a local buffer. Every 250ms, flush the buffer to @MainActor state in a single batch. SwiftUI runs one diff per flush, not one per result. The main thread has time to breathe between batches.

After this change, the MAIN_THREAD_BLOCKED entries disappeared from the duplicate detection phase. The sidebar scrolled smoothly during scans.

Click “Run scan” to compare: per-result updates starve the main thread, while batch flushing keeps the UI responsive.

The logs also surfaced a metric I had initially misread.

sidebar body_eval selection_roundtrip=Xms records the elapsed time since the previous sidebar evaluation. Early on I saw values like 17000ms and assumed something was wrong: no computation should take 17 seconds in a sidebar render.

It does not mean that. The number is time since the last evaluation, not time the evaluation took. A value of 17,000ms means the sidebar was not re-evaluated for 17 seconds, because nothing in it changed. When the scan is running and the sidebar has not yet received new data, there is nothing to re-render. The absence of re-renders is not a bug: it is the @Observable tracking system working correctly, skipping updates when state has not changed.

Misreading that metric would have sent me on a two-day detour optimizing code that was already working correctly. The most dangerous performance metric is the one you think you understand.

One detail about the log location: the app is sandboxed. Logs are written to ~/Library/Containers/com.renala.app/Data/Library/Application Support/Renala/perf-logs/, not the non-sandboxed ~/Library/Application Support/. The container path is where the sandboxed app’s home resolves. If you are tailing logs and they are not updating, you are probably looking in the wrong directory.

Enabling the heartbeat requires setting a defaults key: defaults write com.renala.app enablePerfLogging -bool true. The key goes into the non-sandboxed domain by default, but the sandboxed app reads from its own preferences container at ~/Library/Containers/com.renala.app/Data/Library/Preferences/. Write to the right place, restart the app, then the heartbeat starts.

The batch flush pattern applies anywhere a high-frequency producer feeds a UI consumer. The rule: do not let background work drive UI update frequency. 250ms is imperceptible to a human and gives the main thread room to handle input.

Without the heartbeat log, I would have optimized the sidebar rendering. I was already eyeing List performance, data structures, lazy loading. I had theories. They were all wrong. The rendering was fine. The problem was that the rendering was being triggered thousands of times per second.

Instrument first. Your intuition is not as good as you think it is.

References