Open the log's end reserve only when the process is ending, not at a bug capture's log sync in play.

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>

runtime/dispatch.c

@@ -103,6 +103,7 @@ int rt_ending_enter(void) {
 static void fatal_end(int code, const char *fmt, va_list ap) __attribute__((noreturn));
 static void fatal_end(int code, const char *fmt, va_list ap) {
     if (!rt_ending_enter()) plat_terminate(code);   // a fatal error inside this thread's own report: no second one
+    rt_log_ending();   // the report reaches the log file past its cap (main.c log_sink)
     rt_log_sync();   // main.c: the lines queued for the log thread, then these, written here
     rt_log_raw("FATAL: ", 7);
     rt_vlogf(fmt, ap);

runtime/main.c

@@ -63,11 +63,13 @@ unsigned rt_trace;
 // (NX2NAVI_TRACE can write that much). Lines from before log_open wait in a static buffer: mem_init runs first so that
 // nothing else lands in the guest address space, and an earlier open would put the CRT's heap there.
 // The end of the run still reaches a file past its cap: once the process is ending (rt_log_ending at the start of an
-// orderly end, gfx_present.c rt_exit_begin, and of the frame-time summary, perf.c perf_summary_flush; rt_log_sync at a
-// fatal error and in the crash report), up to LOG_END_RESERVE more bytes are written, counted on their own. A
+// orderly end, gfx_present.c rt_exit_begin, of the frame-time summary, perf.c perf_summary_flush, of a fatal error,
+// dispatch.c fatal_end, of the crash report, crash_handler, of the lost device's watchdog, vk_device.c lost_wait_exit,
+// and in plat_exit, log_sync_ending), up to LOG_END_RESERVE more bytes are written, counted on their own. A
 // trace = perf session reaches the cap in about 90 minutes, and every line after it, the exit summary, "frametime:
 // exit", the stutter map and FATAL lines included, went to stderr only, which a game started from the launcher or
-// Explorer does not keep.
+// Explorer does not keep. rt_log_sync alone does not open the reserve: a bug capture calls it in play
+// (bugcap.c write_log_tail), and the play's lines after it would fill the reserve before the end came.
 #define LOG_KEEP 5
 #define LOG_CAP (64ull << 20)
 #define LOG_END_RESERVE (4ull << 20)
@@ -79,8 +81,8 @@ static char g_log_early[32768];
 static size_t g_log_early_n;
 static uint64_t g_log_bytes;
 
-// stderr's writes (log_sink). g_log_final: rt_log_sync has run, so the process is ending: an exit, a fatal error or a
-// crash report.
+// stderr's writes (log_sink). g_log_final: rt_log_sync has run: an exit, a fatal error, a crash report or a bug
+// capture (bugcap.c).
 static PlatMutex g_err_lock = PLAT_MUTEX_INIT;
 static volatile int32_t g_log_final;
 static volatile int32_t g_log_ending;   // rt_log_ending ran: the process is ending
@@ -106,7 +108,7 @@ static void log_sink(const char *p, size_t n) {
                                           "but for the lines of its end\n";
                 plat_append_write(g_log_file, cut, sizeof cut - 1);
             }
-            if (__atomic_load_n(&g_log_ending, __ATOMIC_ACQUIRE) || __atomic_load_n(&g_log_final, __ATOMIC_ACQUIRE)) {
+            if (__atomic_load_n(&g_log_ending, __ATOMIC_ACQUIRE)) {
                 uint64_t t = __atomic_fetch_add(&g_log_tail, n, __ATOMIC_RELAXED);
                 if (!t) {
                     static const char end[] = "[host] log: the end of the run follows; the lines between the cap and it "
@@ -132,6 +134,12 @@ void rt_log_sync(void) {
     logq_sync();
 }
 
+// plat_exit's first step in a game run (plat_exit_hook): the process ends here, so its last lines reach the file.
+static void log_sync_ending(void) {
+    rt_log_ending();
+    rt_log_sync();
+}
+
 // The console window was closed, or Ctrl+C or Ctrl+Break pressed in it (platform.h plat_console_setup): the end of a
 // closed game window, which writes the settings, the caches and the saves and logs the exit (gfx_present.c
 // gfx_window_closed). Left to Windows, a closed console ended the process with nothing saved.
@@ -227,7 +235,7 @@ static void log_open(int game) {
     // A game run writes its log from the log thread (logq.c), whether the lines go to a log file or to stderr alone.
     const char *e = cfg_get("NX2NAVI_LOG_ASYNC");
     if (!game || (e && !strcmp(e, "0"))) return;
-    plat_exit_hook = rt_log_sync;
+    plat_exit_hook = log_sync_ending;
     if (logq_async()) rt_log("log: lines are written by a thread of their own (NX2NAVI_LOG_ASYNC)");
     else rt_log("log: no log thread; every line is written by the thread that logs it");
 }
@@ -366,6 +374,7 @@ static void crash_handler(const PlatCrash *x) {
     // shared with the fatal error's end (dispatch.c rt_ending_enter): another thread's fault or fatal error waits there
     // while this report is written; a fault inside this thread's own report ends the process at once
     if (!rt_ending_enter()) plat_exit(71);
+    rt_log_ending();   // the report reaches the log file past its cap (log_sink)
     if (__atomic_load_n(&mode_done, __ATOMIC_ACQUIRE) && x->module) {
         rt_log("exit: %s (%#x) in %s while the process was ending, after its work was done and saved%s: the run ends "
                "with its own code %d", x->what, x->code, *x->module ? x->module : "code outside every module",

runtime/vk_device.c

@@ -880,6 +880,7 @@ static void lost_wait_exit(void *arg) {
     int watchdog = arg != NULL;
     for (int t = 0; t < LOST_EXIT_MS + (watchdog ? 0 : 2000); t += 50) plat_sleep_ms(50);
     if (watchdog) {
+        rt_log_ending();   // its line reaches the log file past its cap (main.c log_sink)
         rt_log_sync();   // the queue's locks only tried (bounded): their holder may be the thread that hangs
         rt_log("vk: the end of the run did not finish in %d s; ending it", LOST_EXIT_MS / 1000);
     }

tests/fatal_exit_check.c

@@ -32,6 +32,7 @@ extern const IMAGE_TLS_DIRECTORY _tls_used;
 const void *volatile keep_tls = &_tls_used;
 
 // ---- the runtime fatal_end reaches
+void rt_log_ending(void) {}
 void rt_log_sync(void) {}
 void rt_log_raw(const char *p, size_t n) {
     DWORD w;

tests/log_cap_check.py

@@ -1,8 +1,9 @@
 """The log file's cap and the end of the run (runtime/main.c log_sink): past the cap ordinary lines are dropped, with
-one line that says so; once the process is ending (rt_log_ending, or rt_log_sync at a fatal error and in the crash
-report) its lines are still written, after one line that says the end follows, up to a reserve of their own, however
-much was dropped before. Builds log_sink with a small cap and reserve against stand-ins for the file and stderr. No
-game files.
+one line that says so; once the process is ending (rt_log_ending, which a fatal error and the crash report call before
+rt_log_sync) its lines are still written, after one line that says the end follows, up to a reserve of their own,
+however much was dropped before. rt_log_sync alone (a bug capture in play, runtime/bugcap.c write_log_tail) does not
+open the reserve. Builds log_sink with a small cap and reserve against stand-ins for the file and stderr, and checks
+statically that every end that syncs the log marks it as ending first. No game files.
 
 Usage: python tests/log_cap_check.py [path to clang]"""
 import os
@@ -79,18 +80,31 @@ static int line(const char *tag, int i) {   // returns the line's length
     return n;
 }
 int main(int argc, char **argv) {
-    int fails = 0, how = argc > 1 && !strcmp(argv[1], "sync");
-    int play_n = 0, end_n = 0;
+    // ending: rt_log_ending (an orderly end); fatal: rt_log_ending, then rt_log_sync (a fatal error, the crash report);
+    // capture: rt_log_sync in play (a bug capture), more play, then rt_log_ending
+    const char *how = argc > 1 ? argv[1] : "ending";
+    int fails = 0, play_n = 0, end_n = 0;
     for (int i = 0; i < 1000; i++) play_n = line("play", i);   // 35,000 bytes, many times the cap
-    size_t before_end = file_n;
     int play = count("play "), cut = count("reached 64 MiB");
-    if (how) rt_log_sync();
-    else rt_log_ending();
+    if (!strcmp(how, "capture")) {
+        rt_log_sync();
+        for (int i = 0; i < 1000; i++) line("more", i);
+        int more = count("more "), early = count("the end of the run follows");
+        printf("capture: after rt_log_sync in play %d of 1000 play lines in the file, the end's line %d time(s)\n", more,
+               early);
+        if (more || early) printf("FAIL: rt_log_sync alone opened the end's reserve\n"), fails++;
+    }
+    size_t before_end = file_n;
+    if (strcmp(how, "fatal")) {
+        rt_log_ending();
+    } else {
+        rt_log_ending();
+        rt_log_sync();
+    }
     for (int i = 0; i < 100; i++) end_n = line("last", i);   // 3,400 bytes, more than the reserve
     int end = count("last "), follows = count("the end of the run follows");
-    printf("%s: %d play lines in the file, the cut line %d time(s); after %s %d end lines, the line before them %d "
-           "time(s); the file %zu bytes (cap %llu, reserve %llu)\n", how ? "rt_log_sync" : "rt_log_ending", play, cut,
-           how ? "rt_log_sync" : "rt_log_ending", end, follows, file_n, LOG_CAP, LOG_END_RESERVE);
+    printf("%s: %d play lines in the file, the cut line %d time(s); %d end lines, the line before them %d time(s); the "
+           "file %zu bytes (cap %llu, reserve %llu)\n", how, play, cut, end, follows, file_n, LOG_CAP, LOG_END_RESERVE);
     if (play != (int)(LOG_CAP / play_n) || cut != 1) printf("FAIL: lines past the cap\n"), fails++;
     if (follows != 1 || end != (int)(LOG_END_RESERVE / end_n)) printf("FAIL: the end's lines\n"), fails++;
     if (file_n - before_end > LOG_END_RESERVE + 200) printf("FAIL: past the reserve\n"), fails++;
@@ -99,6 +113,37 @@ int main(int argc, char **argv) {
 '''
 
 
+def static_checks():
+    """Every end that syncs the log marks the process as ending first, so its lines reach the file past the cap."""
+    bad = 0
+    rt = ROOT / 'runtime'
+    ends = [('main.c', 'static void crash_handler(const PlatCrash *x)'),
+            ('main.c', 'static void log_sync_ending(void)'),
+            ('dispatch.c', 'static void fatal_end(int code, const char *fmt, va_list ap) {'),
+            ('vk_device.c', 'static void lost_wait_exit(void *arg)')]
+    for file, sig in ends:
+        text = (rt / file).read_text(encoding='utf-8')
+        if sig not in text:
+            print(f'static: {file}: {sig} is missing: FAIL', flush=True)
+            bad += 1
+            continue
+        start = text.index(sig)
+        brace = text.index('{', start)
+        depth, end = 1, brace + 1
+        while depth:
+            depth += (text[end] == '{') - (text[end] == '}')
+            end += 1
+        body = re.sub(r'//[^\n]*', '', text[start:end])
+        e, s = body.find('rt_log_ending()'), body.find('rt_log_sync()')
+        ok = 0 <= e < s
+        print(f'static: {file} {sig.split("(")[0].split()[-1].lstrip("*")} calls rt_log_ending before rt_log_sync: '
+              f'{"ok" if ok else "FAIL"}', flush=True)
+        bad += not ok
+    ok = 'plat_exit_hook = log_sync_ending;' in source
+    print(f'static: main.c plat_exit_hook is log_sync_ending: {"ok" if ok else "FAIL"}', flush=True)
+    return bad + (not ok)
+
+
 def main():
     parts = [HARNESS]
     parts.append(re.search(r'static PlatMutex g_err_lock = PLAT_MUTEX_INIT;\n(.*?\n)\nvoid rt_log_ending', source, re.S)
@@ -116,8 +161,8 @@ def main():
     if os.name == 'nt' and MSYS_BIN.exists():
         env['PATH'] = str(MSYS_BIN) + os.pathsep + env.get('PATH', '')
     subprocess.check_call([compiler(), '-O1', '-g', '-Wall', '-Wno-unused-function', str(src), '-o', str(exe)], env=env)
-    bad = 0
-    for how in ('ending', 'sync'):
+    bad = static_checks()
+    for how in ('ending', 'fatal', 'capture'):
         bad += subprocess.run([str(exe), how], env=env, timeout=60).returncode != 0
     print(f'log_cap_check: {"FAILED" if bad else "ok"}')
     return 1 if bad else 0