[DUDUYG]

The problem

stderr is unbuffered (hos_main.c), so every line the log writer takes is a write of its own. In play that is 30–90 writes a second, each one extending hookshot_log.txt in the game folder.

With the game on a slow disk (a SATA SSD, 90% full, on my PC) those small appends keep the disk busy:

• Its 4 KB reads take 10–500 ms, where they normally take 0.4 ms.
• What the game reads from that disk meanwhile (pages of hookshot.exe, the game's files) waits just as long.

The fix

• log_write joins the lines it is given into one fwrite. On the text-mode stream that is one WriteFile, or a few for a large batch.
• After the line it is woken for, log_main waits up to HOS_LOG_BATCH_MS so the lines of that time go out together:
  • The default is 250 ms, the most is 2000, and 0 behaves as before.
  • The wait is on the existing condition variable: log_queue wakes it at each line.
  • When the queue is half full (1,024 lines), the batch goes out at once, before a burst can fill the queue. A full queue would make the thread that logs write the line itself.
• Nothing waiting is lost. Every way out already writes the queue first (log_flush at exit, in hos_fatal and at the window's close, and log_crash_filter), and the writer holds no lock while it waits.
• A line therefore reaches the file up to 250 ms later than before. A process killed from outside (TerminateProcess) could lose up to that much. Before, it could lose whatever the writer had not reached yet.

Measured

Test setup:

• RTX 5070, driver 621.01, Ryzen 7 9800X3D, 31 GB.
• Game and its log on a SATA SSD; the test harness's own files on another disk.
• Scripted headless route: load a save, then walk outdoors on the Kokiri path. In play = from present 3300 on, about 2,820 frames a run.
• 3 runs of each version, alternated, on the same build. Both arms also had perf(vk): write the pipeline cache only when its data changed (no 1.1 GB rewrite at every start) #1660, so the 1.1 GB pipeline cache rewrite is out of the picture.

	one write per line (HOS_LOG_BATCH_MS=0)	batched (default)
game-disk 4 KB reads over 10 ms in play	46 / 12 / 0	0 / 0 / 2
game-disk 4 KB reads over 100 ms	6 / 1 / 0	0 / 0 / 0
worst game-disk read	202 / 526 / 7 ms	3 / 4 / 18 ms
frames over 50 ms	0 / 4 / 2	0 / 1 / 0
worst frame	40 / 111 / 367* ms	41 / 51 / 41 ms

* That 367 ms frame overlapped a page-file read on the other disk (memory pressure), not the game disk.

The effect is intermittent: one of the three unbatched runs was clean. In the second run, a cluster of 40–111 ms frames lined up with game-disk reads of 20–53 ms and with 800–2,000 pages read in by hard faults in each of those frames (hookshot.exe is on that disk). The average stays at 60 fps (capped).

Tests

tests/test_log_batch.py extracts the Windows log block of host/hos_thread.c unmodified, with fputs, fwrite and fflush as spies. It runs on real threads, SRW locks and condition variables, and checks five cases:

• batch: with a 1 s wait, the lines of that time go out in one write, in order, and none before the wait ends.
• default: with no setting, a line goes out after its 250 ms.
• off: 0 writes a line at once.
• burst: with a 2 s wait, 1,500 lines queued at once: the first 1,024 go out within 1 s, every line was queued, and none was written by the logging thread.
• flush: log_flush writes what waits, and the writer's wait then ends with nothing written twice.

It is Windows only; run_all.py skips it on Linux. GCC's C front end warns that log_main (a for (;;) thread) has no return statement, so the fixture turns -Wreturn-type off around the extracted block only; clang, which builds the game, does not warn.

Results:

• This PR passes all 5 cases, 4 times in a row.
• main's writer fails batch, default and flush.
• A plain Sleep in place of the condition-variable wait fails burst.

Also checked:

• host/hos_thread.c compiles with -Wall -Wextra with the same single warning as main (an unused parameter at the file's end).
• tests/run_all.py: 225 checks, 33 skipped. test_log_batch.py passes. Two checks fail for reasons of this PC, as on main:
  • test_precompile_compute_guard.py needs windows.h for an MSVC target.
  • test_nup_paths.py needs the symlink privilege.

🤖 Generated with Claude Code