The review of the log tail change found that main.c log_sink opened the 4 MiB reserve past the cap on g_log_final as
well as on g_log_ending. bugcap.c write_log_tail calls rt_log_sync in play, which sets g_log_final, so after a bug
capture in a trace = perf session past the cap, ordinary play lines filled the reserve (about 6 minutes at 12 KB/s),
the end's lines were dropped again, and the "end of the run follows" line came mid-run.
The reserve is now keyed on g_log_ending alone, as E-10's design had it. The ends that relied on rt_log_sync now call
rt_log_ending first: dispatch.c fatal_end and main.c crash_handler right after their guard, vk_device.c
lost_wait_exit's watchdog before its sync, and plat_exit through the new main.c log_sync_ending (plat_exit_hook in a
game run), so every path that ends through plat_exit marks the end too. rt_exit_begin and perf_summary_flush call it
as before.
Not reproduced in the game before the change. tests/log_cap_check.py gains a capture case (rt_log_sync in play, 1000
more play lines, then the end): on the code before this change 58 play lines took the reserve, the end line came at
the sync and no end line reached the file; now no play line passes the cap and the end's lines fill the reserve. A
fatal case runs rt_log_ending and then rt_log_sync, and static checks hold crash_handler, log_sync_ending, fatal_end
and lost_wait_exit to calling rt_log_ending before rt_log_sync. log_cap_check, fatal_exit_check (with a stand-in for
rt_log_ending) and the compile checks of main.c, dispatch.c and vk_device.c pass, with no new -Wall warnings.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
main.c log_sink wrote nothing to the file once g_log_bytes passed LOG_CAP: every later line, the exit summary,
"frametime: exit", the stutter map's exit lines and FATAL and crash lines included, went to stderr only, which a
game started from the launcher or Explorer does not keep. A trace = perf session reaches the cap in about 90
minutes (the fresh 0.10.0 log grew 12 KB/s), and the play-test asks for an hour or more of exactly that. A reserve
compared against g_log_bytes would not help: that counter adds every line, dropped ones too, so 4 MiB of dropped
lines (under 6 minutes at that rate) would use it up before the end came.
The new rt_log_ending marks the process as ending; rt_exit_begin (the orderly ends) and perf_summary_flush (the
frame-time summary, also on the cheats rebuild exit) call it, and rt_log_sync (a fatal error, the crash report)
counts as ending too. The exit summary and the stutter map are written before rt_log_sync, so keying on
g_log_final alone would have missed them. While ending, a line past the cap goes to the file through
g_log_tail, a counter of the bytes written past the cap, up to LOG_END_RESERVE (4 MiB), after one line saying the
end of the run follows. The cut line says the end will still come. The file can end 4 MiB past the cap.
perf_summary_flush now calls rt_log_ending before ft_stop, so tests/exit_order_check.py's static check of it wants
ft_stop before ft_report rather than first. The check also prints one closing line for the static checks and the
program together: the program's own "ok" line had hidden a failing static check.
Not reproduced before the change (no log here reached the cap). The new tests/log_cap_check.py builds log_sink
with a 4 KiB cap and a 2 KiB reserve: past the cap ordinary lines are dropped with one cut line, and after
rt_log_ending or rt_log_sync the end's lines fill the reserve after one "end follows" line, however much was
dropped before. exit_order_check (rt_exit_begin marks the end once; exit code 0 at this commit), logq_check and the
compile checks pass.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
