// Cross-platform "where did it hang?" logger. // // On DOS/Amiga/ST: joeylog.txt is held open across calls and FLUSHED // AFTER EVERY LINE -- safe logs are more important than fast logs. A // crash, hang, or hard kill therefore always leaves every line emitted // so far on disk. // // On the IIgs the per-line-flush design is a triple failure // (claudeDocs/PERF-AUDIT.md #80/#82): the libc fflush does not commit through the // GS/OS FST (nothing persists until fclose), each real FST write costs // seconds of emulated floppy time, and a write can wedge indefinitely // inside SmartPort firmware retries -- one such wedge stalled the UBER // benchmark for 18+ emulated minutes. So on IIgs the lines land in a // RAM ring instead: gJoeyLogRing/gJoeyLogRingHead are non-static so // headless-MAME Lua probes can drain the log LIVE from emulated memory // (scripts/bench-iigs.sh), and jlLogFlush() writes the accumulated ring // to joeylog.txt in one open/write/close pass (fclose is the only // operation that actually commits) for on-hardware persistence. #include #include #include #include #include "joey/platform.h" #include "joey/debug.h" static const char *kLogPath = "joeylog.txt"; #ifdef JOEY_LOG_SERIAL_TEE // Supplied by the port. Declared ahead of the platform split because BOTH log // implementations below tee through it. void jlpLogTee(const char *text); #endif #ifdef JOEYLIB_PLATFORM_IIGS // Ring capacity. Head is a free-running total-bytes-written counter // (uint16_t, wraps at 65536); the ring index is head % size, so the // size must divide 65536 for the wrap to stay aligned. A Lua reader // tracks its own last-read count and detects overruns by delta > size. #define JOEY_LOG_RING_BYTES 8192u uint8_t gJoeyLogRing[JOEY_LOG_RING_BYTES]; uint16_t gJoeyLogRingHead = 0; // ----- Prototypes ----- static void ringAppend(const char *text); static void ringAppend(const char *text) { uint16_t head; uint16_t idx; #ifdef JOEY_LOG_SERIAL_TEE // Opt-in live mirror of the log to the port's serial line. The 8 KB ring // holds only the last ~100 lines and jlLogFlush needs a writable disk with // room on it; a run that outlives either loses exactly the output being // hunted. The tee is unbounded, needs no disk, and arrives in real time, // which is what makes a wedged run diagnosable at all. OFF by default: // it is a debugging build option, not a shipping cost. jlpLogTee(text); #endif // Explicit read-modify-write of the global (never `++`/`+=` on a // global -- the 65816 inc-abs/DBR trap). head = gJoeyLogRingHead; while (*text != '\0') { idx = (uint16_t)(head & (JOEY_LOG_RING_BYTES - 1u)); gJoeyLogRing[idx] = (uint8_t)*text; text++; head = (uint16_t)(head + 1u); } gJoeyLogRingHead = head; } void jlLog(const char *msg) { if (msg == NULL) { return; } ringAppend(msg); ringAppend("\n"); } void jlLogF(const char *fmt, ...) { char line[200]; va_list args; if (fmt == NULL) { return; } va_start(args, fmt); (void)vsnprintf(line, sizeof(line), fmt, args); va_end(args); ringAppend(line); // Callers' formats mostly end in \n already; jlLog adds one for // plain strings, so nothing is appended here. } // One-shot dump of everything the ring has seen to joeylog.txt. // open/write/CLOSE per call: fclose is the only point the FST commits // (#80), and batching all lines into one pass keeps the floppy cost to // a single visit instead of one per line. Mode "w": the dump always // contains the ENTIRE surviving ring, so truncate-on-flush both makes // repeated flushes idempotent and lets jlLogReset stay disk-free (see // below). void jlLogFlush(void) { FILE *fp; uint16_t head; uint16_t start; uint16_t count; uint16_t i; uint16_t idx; head = gJoeyLogRingHead; if (head == 0u) { return; } fp = fopen(kLogPath, "w"); if (fp == NULL) { return; } // If the ring wrapped, the oldest surviving byte is head - size. count = head; start = 0; if (count > JOEY_LOG_RING_BYTES) { start = (uint16_t)(head - JOEY_LOG_RING_BYTES); count = JOEY_LOG_RING_BYTES; } for (i = 0; i < count; i++) { idx = (uint16_t)((uint16_t)(start + i) & (JOEY_LOG_RING_BYTES - 1u)); fputc((int)gJoeyLogRing[idx], fp); } fclose(fp); } // Ring-only: NO disk I/O here. The old truncate write (fopen "w" + // fclose) was the first floppy WRITE any app performed and wedged // forever in SmartPort firmware retries under headless MAME -- the // same #82 failure class the RAM ring exists to avoid. UBER never // calls jlLogReset, so the write path lay unexercised until the // spacetaxi acceptance test hit it (hang before the first log line, // PC spinning in the ROM WAIT loop). jlLogFlush opens with "w" now, // so the on-disk file still ends up truncated-to-current on the next // flush. void jlLogReset(void) { gJoeyLogRingHead = 0; } #else /* not JOEYLIB_PLATFORM_IIGS */ static FILE *gLogFp = NULL; /* 16 KB full buffer so a single log line's many small vfprintf writes * coalesce into one host write; jlLog/jlLogF then fflush once per * line. Default stdio buffers are only ~512 bytes, which would split a * long line across multiple writes. */ #define JOEY_LOG_BUF_BYTES 16384 static char gLogBuf[JOEY_LOG_BUF_BYTES]; /* Lazy-open. Returns NULL if the open failed (silently disable). */ static FILE *logFile(void) { if (gLogFp == NULL) { gLogFp = fopen(kLogPath, "a"); if (gLogFp != NULL) { (void)setvbuf(gLogFp, gLogBuf, _IOFBF, sizeof(gLogBuf)); } } return gLogFp; } void jlLog(const char *msg) { FILE *fp; if (msg == NULL) { return; } #ifdef JOEY_LOG_SERIAL_TEE jlpLogTee(msg); jlpLogTee("\n"); #endif fp = logFile(); if (fp == NULL) { return; } fputs(msg, fp); fputc('\n', fp); fflush(fp); } void jlLogF(const char *fmt, ...) { FILE *fp; va_list args; if (fmt == NULL) { return; } fp = logFile(); #ifdef JOEY_LOG_SERIAL_TEE // Format once into a buffer so the same bytes reach the file and the wire. // Only under the tee: default builds keep the straight vfprintf, which has // no line-length ceiling. { char line[200]; va_start(args, fmt); (void)vsnprintf(line, sizeof(line), fmt, args); va_end(args); jlpLogTee(line); jlpLogTee("\n"); if (fp == NULL) { return; } fputs(line, fp); fputc('\n', fp); fflush(fp); return; } #else if (fp == NULL) { return; } va_start(args, fmt); vfprintf(fp, fmt, args); va_end(args); fputc('\n', fp); fflush(fp); #endif } void jlLogFlush(void) { if (gLogFp != NULL) { fflush(gLogFp); } } void jlLogReset(void) { if (gLogFp != NULL) { fclose(gLogFp); gLogFp = NULL; } /* Truncate by opening for write then closing; subsequent * jlLog* will reopen for append. */ { FILE *fp = fopen(kLogPath, "w"); if (fp != NULL) { fclose(fp); } } } #endif /* JOEYLIB_PLATFORM_IIGS */