verbosity: flush errors and warnings per line, buffer the rest

The re-audit's remaining dominant cost with file logging on was the
unconditional per-line fflush, kept in the correctness pass for
crash durability. This takes the middle it prescribed: lines whose
tag is [ERROR] or [WARN] still reach the OS before the logging call
returns - they must survive the crash whose report they may be -
and informational traffic rides stdio's buffer, becoming durable at
the flush points: any later flushed line on the same stream, and
rarch_log_file_deinit()'s fclose. The traded tail is documented at
the decision: a hard crash can lose buffered INFO/DEBUG lines
written after the last error or warning. Tags are matched by exact
label, so a core-supplied custom tag rides the buffer like INFO.

rarch_log_line_emit() carries the verdict as a parameter, computed
from the tag by every caller - the generic branch, both Apple file
writes, and the Android file arm - so the policy is one predicate,
not one per region. The LibNX mutex still wraps the write and any
flush as one unit.

The log-atomicity harness grows the durability lane: after the
racing writers finish, a RARCH_ERR line must be readable from the
file before any deinit runs - that is the flush promise - while
informational lines are deliberately not asserted present or absent
mid-run, since stdio may flush them whenever it likes; the whole-
file scan still counts every writer line after deinit, which is the
buffered path's own promise, and skips the marker line whose shape
is not a writer line's.

Verified: the extended harness green three consecutive runs, the
logger-macros suite green in all four configurations, LibNX,
Android and Apple-macOS stub syntax passes, C89 gate, full build
clean, thread-read audit 0 findings, and the 74-lane compile
matrix.
This commit is contained in:
LibretroAdmin authored and libretroadmin committed 2026-09-16 10:24:53 +02:00
1 parent 650b20a30b
commit 4552975f37
2 files changed
+57 -7

No files matched your search

@@ -150,6 +150,31 @@ int main(int argc, char *argv[])
if (ta) sthread_join(ta);
if (tb) sthread_join(tb);
/* Flush-policy lane: an error line is durable the moment the
* call returns - readable from the file before any deinit -
* while informational lines may ride stdio's buffer until the
* next flush point (their presence mid-run is therefore not
* asserted either way; the whole-file scan below still counts
* every line after deinit's fclose flushes the tail). */
RARCH_ERR("flush-lane error line\n");
{
FILE *ef;
int found = 0;
if ((ef = fopen(log_path, "rb")))
{
char *eline = NULL;
size_t ecap = 0;
ssize_t elen;
while ((elen = getline(&eline, &ecap, ef)) != -1)
if (strstr(eline, "flush-lane error line"))
found = 1;
free(eline);
fclose(ef);
}
CHECK(found,
"RARCH_ERR line not durable before deinit (flush policy)");
}
retro_main_log_file_deinit();
if (!(f = fopen(log_path, "rb")))
@@ -162,6 +187,9 @@ int main(int argc, char *argv[])
ssize_t n;
while ((n = getline(&line, &line_cap, f)) > 0)
{
/* The flush-policy lane's marker line has its own shape. */
if (strstr(line, "flush-lane error line"))
continue;
size_t len = (size_t)n;
char which;
+29 -7
View File
@@ -305,8 +305,26 @@ static const char *rarch_log_line_format(char *line, size_t line_size,
return line;
}
/* One write, one flush, under the LibNX mutex where it exists. */
static void rarch_log_line_emit(FILE *fp, const char *out)
/* Errors and warnings must survive a crash whose report they may be,
* so their lines reach the OS before this returns. Informational
* traffic rides stdio's buffer - the per-line flush was the file
* sink's dominant cost - and becomes durable at the flush points:
* rarch_log_file_deinit()'s fclose, and any later flushed line on
* the same stream. The cost of that ride is the documented one: a
* hard crash can lose the buffered tail of INFO/DEBUG lines written
* after the last error or warning. Tags are matched by exact label;
* a core-supplied custom tag rides the buffer like INFO. */
static bool rarch_log_tag_wants_flush(const char *tag_v)
{
return memcmp(tag_v, FILE_PATH_LOG_ERROR,
sizeof(FILE_PATH_LOG_ERROR)) == 0
|| memcmp(tag_v, FILE_PATH_LOG_WARN,
sizeof(FILE_PATH_LOG_WARN)) == 0;
}
/* One write - and, for lines that must not wait, one flush - under
* the LibNX mutex where it exists. */
static void rarch_log_line_emit(FILE *fp, const char *out, bool flush)
{
#if defined(HAVE_LIBNX)
/* Around exactly one write and its flush; libnx newlib's stdio
@@ -314,7 +332,8 @@ static void rarch_log_line_emit(FILE *fp, const char *out)
mutexLock(&main_verbosity_st.mtx);
#endif
fputs(out, fp);
fflush(fp);
if (flush)
fflush(fp);
#if defined(HAVE_LIBNX)
mutexUnlock(&main_verbosity_st.mtx);
#endif
@@ -332,7 +351,7 @@ static void rarch_log_line_write(FILE *fp, const char *tag_v,
const char *out = rarch_log_line_format(line, sizeof(line), &heap,
tag_v, fmt, ap);
rarch_log_line_emit(fp, out);
rarch_log_line_emit(fp, out, rarch_log_tag_wants_flush(tag_v));
free(heap);
}
#endif
@@ -421,7 +440,8 @@ void RARCH_LOG_V(const char *tag, const char *fmt, va_list ap)
* guard, every line would print twice in the no-file case. */
printf("%s", out);
if (main_verbosity_st.initialized && fp)
rarch_log_line_emit(fp, out);
rarch_log_line_emit(fp, out,
rarch_log_tag_wants_flush(tag_v));
#else
{
@@ -453,7 +473,8 @@ void RARCH_LOG_V(const char *tag, const char *fmt, va_list ap)
#endif
if (main_verbosity_st.initialized && fp)
rarch_log_line_emit(fp, out);
rarch_log_line_emit(fp, out,
rarch_log_tag_wants_flush(tag_v));
}
#endif
}
@@ -463,7 +484,8 @@ void RARCH_LOG_V(const char *tag, const char *fmt, va_list ap)
/* stdio's per-call lock keeps the single write whole under
* concurrent writers; the format above already took the
* heap detour for wide lines. */
rarch_log_line_emit(fp, out);
rarch_log_line_emit(fp, out,
rarch_log_tag_wants_flush(tag_v));
#endif
free(heap);