diff --git a/diagnostic/build-2b54872c.json b/diagnostic/build-2b54872c.json new file mode 100644 index 00000000..fff6757a --- /dev/null +++ b/diagnostic/build-2b54872c.json @@ -0,0 +1,86 @@ +{ + "generated_at": "2026-06-21T10:12:02.735403+00:00", + "commit": "2b54872c", + "diagnostic_logd": "diagnostic/build-2b54872c.logd", + "diagnostic_logd_error": null, + "chunked": false, + "chunk_size_bytes": null, + "password": "eaa19d08ed6752bc7db4", + "decrypt_command": "encryptly unpack diagnostic/build-2b54872c.logd --password eaa19d08ed6752bc7db4", + "total_modules": 10, + "passed": 2, + "failed": 8, + "modules": [ + { + "name": "backend", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [Errno 2] No such file or directory: 'cargo'" + }, + { + "name": "frontend", + "status": "PASS", + "elapsed_seconds": 3.823, + "artifact": "/Users/qingfeng/Desktop/\u81ea\u52a8\u642c\u7816/TentOfTrials-gautam-logger/frontend/dist", + "output": "> tent-frontend@0.0.0 build\n> tsc -b && vite build\n\nvite v6.4.3 building for production...\ntransforming...\n\u2713 100 modules transformed.\nrendering chunks...\ncomputing gzip size...\ndist/index.html 0.62 kB \u2502 gzip: 0.34 kB\ndist/assets/state-BkjSKDbY.js 8.91 kB \u2502 gzip: 3.55 kB \u2502 map: 57.15 kB\ndist/assets/vendor-CREcWLHI.js 48.93 kB \u2502 gzip: 17.22 kB \u2502 map: 481.27 kB\ndist/assets/index-CyxcoTyU.js 231.32 kB \u2502 gzip: 72.02 kB \u2502 map: 1,044.42 kB\n\u2713 built in 527ms" + }, + { + "name": "market", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [Errno 2] No such file or directory: 'go'" + }, + { + "name": "frailbox", + "status": "FAIL", + "elapsed_seconds": 0.032, + "artifact": null, + "output": "gcc -Wall -Wextra -Wpedantic -std=c2x -O2 -g -D_FORTIFY_SOURCE=3 -fstack-protector-strong -fPIE -Iinclude -MMD -MP -c src/arena.c -o build/src/arena.o\nsrc/arena.c:17:23: error: use of undeclared identifier 'MAP_HUGETLB'\n 17 | mmap_flags |= MAP_HUGETLB;\n | ^\nsrc/arena.c:179:17: warning: comparison of distinct pointer types ('const void *' and 'char *') [-Wcompare-distinct-pointer-types]\n 179 | ptr < (char *)region->start + region->size) {\n | ~~~ ^ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~\n1 warning and 1 error generated.\nmake: *** [build/src/arena.o] Error 1" + }, + { + "name": "engine", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [Errno 2] No such file or directory: 'cmake'" + }, + { + "name": "compliance", + "status": "FAIL", + "elapsed_seconds": 0.009, + "artifact": null, + "output": "The operation couldn\u2019t be completed. Unable to locate a Java Runtime.\nPlease visit http://www.java.com for information on installing Java." + }, + { + "name": "v2-market-stream", + "status": "PASS", + "elapsed_seconds": 0.051, + "artifact": null, + "output": "Syntax OK" + }, + { + "name": "nfc-scanner", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [Errno 2] No such file or directory: 'luac'" + }, + { + "name": "openapi-haskell", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [Errno 2] No such file or directory: 'ghc'" + }, + { + "name": "openapi-tools", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [Errno 2] No such file or directory: 'luac'" + } + ], + "pr_note": "Include the encrypted diagnostic logd artifact(s): diagnostic/build-2b54872c.logd. The encrypted .logd is the required diagnostic content for PR review; this JSON file is metadata. Maintainers may ask you to remove these diagnostic artifacts before merging." +} diff --git a/diagnostic/build-2b54872c.logd b/diagnostic/build-2b54872c.logd new file mode 100644 index 00000000..47433ae3 Binary files /dev/null and b/diagnostic/build-2b54872c.logd differ diff --git a/docs/OPERATIONS.md b/docs/OPERATIONS.md index 58642e7b..2903ba9c 100644 --- a/docs/OPERATIONS.md +++ b/docs/OPERATIONS.md @@ -206,6 +206,19 @@ FROM pg_stat_activity WHERE state = 'idle' AND age > interval '1 hour'; ``` +## Frailbox Legacy Logger Error Handling + +The frailbox legacy logger writes to `stderr` unless `LOG_FILE` is set. If the +configured file cannot be opened during startup, the logger reports the path and +system error to `stderr`, then continues using `stderr` so startup logging is not +lost. + +If a configured log file later fails during write or flush, the logger reports +the failed operation, closes the bad stream, and falls back to `stderr` for the +current and future log messages. Shutdown also reports flush or close failures +instead of ignoring them. These fallbacks preserve existing logging behavior for +healthy files while making common filesystem failures visible to operators. + ## Capacity Planning ### Resource Utilization diff --git a/frailbox/Makefile b/frailbox/Makefile index d4383d85..d2cf5750 100644 --- a/frailbox/Makefile +++ b/frailbox/Makefile @@ -15,7 +15,7 @@ DEPS = $(OBJS:.o=.d) TARGET = frailbox -.PHONY: all clean +.PHONY: all clean logger-error-test all: $(TARGET) @@ -37,7 +37,12 @@ distclean: clean test: $(TARGET) ./$(TARGET) --sandbox-type seccomp --memory-limit 64 --verbose +logger-error-test: + @mkdir -p $(BUILDDIR)/tests + $(CC) $(CFLAGS) -I$(INCDIR) tests/test_logger_error_handling.c src/logger.c -o $(BUILDDIR)/tests/test_logger_error_handling -lpthread + ./$(BUILDDIR)/tests/test_logger_error_handling + valgrind: $(TARGET) valgrind --leak-check=full --show-leak-kinds=all ./$(TARGET) -.PHONY: all clean distclean test valgrind +.PHONY: all clean distclean test logger-error-test valgrind diff --git a/frailbox/src/logger.c b/frailbox/src/logger.c index f1a7aa1a..014442d1 100644 --- a/frailbox/src/logger.c +++ b/frailbox/src/logger.c @@ -129,6 +129,12 @@ static int g_log_level = DEFAULT_LOG_LEVEL; */ static FILE *g_log_file = NULL; +/** + * Path of the configured log file. Kept only for diagnostics when the + * logger has to fall back to stderr after an I/O failure. + */ +static char g_log_file_path[512] = ""; + /** * Whether to include timestamps in log output. * This can be disabled for performance-critical logging paths. @@ -325,6 +331,47 @@ static void ring_buffer_push(const char *message) pthread_mutex_unlock(&g_ring_buffer.ring_mutex); } +static void set_log_file_path(const char *path) +{ + if (path == NULL || path[0] == '\0') { + g_log_file_path[0] = '\0'; + return; + } + + strncpy(g_log_file_path, path, sizeof(g_log_file_path) - 1); + g_log_file_path[sizeof(g_log_file_path) - 1] = '\0'; +} + +static void report_log_file_error(const char *operation, const char *path, int err) +{ + const char *display_path = (path != NULL && path[0] != '\0') ? path : ""; + const char *message = (err != 0) ? strerror(err) : "unknown error"; + + fprintf(stderr, "Legacy logger %s failed for '%s': %s\n", + operation, display_path, message); +} + +static void fallback_to_stderr(FILE *failed_file, const char *operation, int err) +{ + char failed_path[sizeof(g_log_file_path)]; + strncpy(failed_path, g_log_file_path, sizeof(failed_path) - 1); + failed_path[sizeof(failed_path) - 1] = '\0'; + + report_log_file_error(operation, failed_path, err); + fprintf(stderr, "Legacy logger falling back to stderr.\n"); + + if (failed_file != NULL && failed_file != stderr) { + clearerr(failed_file); + if (fclose(failed_file) != 0) { + int close_err = errno != 0 ? errno : EIO; + report_log_file_error("close after fallback", failed_path, close_err); + } + } + + g_log_file = stderr; + set_log_file_path(NULL); +} + /* ------------------------------------------------------------------ */ /* PUBLIC API */ /* ------------------------------------------------------------------ */ @@ -377,15 +424,19 @@ int log_init(void) const char *env_log_file = getenv("LOG_FILE"); if (env_log_file != NULL && strlen(env_log_file) > 0) { + set_log_file_path(env_log_file); g_log_file = fopen(env_log_file, "a"); if (g_log_file == NULL) { - fprintf(stderr, "Failed to open log file '%s': %s\n", - env_log_file, strerror(errno)); + int open_err = errno != 0 ? errno : EIO; + report_log_file_error("open", env_log_file, open_err); + fprintf(stderr, "Legacy logger falling back to stderr.\n"); /* Fall back to stderr */ g_log_file = stderr; + set_log_file_path(NULL); } } else { g_log_file = stderr; + set_log_file_path(NULL); } const char *env_module = getenv("LOG_MODULE"); @@ -525,13 +576,30 @@ void log_message(int level, const char *file, int line, const char *fmt, ...) buffer[total_len + 1] = '\0'; } - /* Write to output */ - if (g_log_file != NULL) { - fputs(buffer, g_log_file); - fflush(g_log_file); - } else { - fputs(buffer, stderr); - fflush(stderr); + /* Write to output. A configured file can become unwritable after init + * (disk full, revoked permissions, stale mount), so downgrade to stderr + * instead of silently dropping future logs. */ + FILE *target = g_log_file != NULL ? g_log_file : stderr; + if (fputs(buffer, target) == EOF) { + int write_err = errno != 0 ? errno : EIO; + if (target != stderr) { + fallback_to_stderr(target, "write", write_err); + fputs(buffer, stderr); + fflush(stderr); + } else { + report_log_file_error("write", NULL, write_err); + clearerr(stderr); + } + } else if (fflush(target) == EOF) { + int flush_err = errno != 0 ? errno : EIO; + if (target != stderr) { + fallback_to_stderr(target, "flush", flush_err); + fputs(buffer, stderr); + fflush(stderr); + } else { + report_log_file_error("flush", NULL, flush_err); + clearerr(stderr); + } } pthread_mutex_unlock(&log_mutex); @@ -551,12 +619,25 @@ void log_shutdown(void) pthread_mutex_lock(&log_mutex); if (g_log_file != NULL && g_log_file != stderr) { - fflush(g_log_file); - fclose(g_log_file); + char closing_path[sizeof(g_log_file_path)]; + strncpy(closing_path, g_log_file_path, sizeof(closing_path) - 1); + closing_path[sizeof(closing_path) - 1] = '\0'; + + if (fflush(g_log_file) == EOF) { + int flush_err = errno != 0 ? errno : EIO; + report_log_file_error("shutdown flush", closing_path, flush_err); + clearerr(g_log_file); + } + + if (fclose(g_log_file) != 0) { + int close_err = errno != 0 ? errno : EIO; + report_log_file_error("shutdown close", closing_path, close_err); + } g_log_file = NULL; } g_log_level = LOG_LEVEL_NONE; + set_log_file_path(NULL); pthread_mutex_unlock(&log_mutex); diff --git a/frailbox/tests/test_logger_error_handling.c b/frailbox/tests/test_logger_error_handling.c new file mode 100644 index 00000000..1262b9eb --- /dev/null +++ b/frailbox/tests/test_logger_error_handling.c @@ -0,0 +1,122 @@ +#include +#include +#include +#include +#include + +#include "../include/logger.h" + +static int failures = 0; + +#define EXPECT_TRUE(condition, message) do { \ + if (!(condition)) { \ + fprintf(stderr, "FAIL: %s\n", message); \ + failures++; \ + } \ +} while (0) + +static void clear_logger_env(void) +{ + unsetenv("LOG_FILE"); + unsetenv("LOG_LEVEL"); + unsetenv("LOG_MODULE"); + unsetenv("LOG_SOURCE_INFO"); + unsetenv("LOG_NO_TIMESTAMPS"); +} + +static int file_contains(const char *path, const char *needle) +{ + FILE *fp = fopen(path, "r"); + if (fp == NULL) { + return 0; + } + + char buffer[4096]; + size_t nread = fread(buffer, 1, sizeof(buffer) - 1, fp); + fclose(fp); + buffer[nread] = '\0'; + return strstr(buffer, needle) != NULL; +} + +static void test_open_failure_falls_back_to_stderr(void) +{ + char dir_template[] = "/tmp/frailbox-log-open-XXXXXX"; + char *dir = mkdtemp(dir_template); + EXPECT_TRUE(dir != NULL, "mkdtemp should create a temporary directory"); + if (dir == NULL) { + return; + } + + char bad_path[512]; + snprintf(bad_path, sizeof(bad_path), "%s/missing/log.txt", dir); + + clear_logger_env(); + setenv("LOG_FILE", bad_path, 1); + setenv("LOG_LEVEL", "debug", 1); + + EXPECT_TRUE(log_init() == 0, "log_init should succeed with stderr fallback"); + LOG_ERROR("open fallback marker"); + log_shutdown(); + + rmdir(dir); + clear_logger_env(); +} + +static void test_regular_file_logging_still_works(void) +{ + char path_template[] = "/tmp/frailbox-log-file-XXXXXX"; + int fd = mkstemp(path_template); + EXPECT_TRUE(fd >= 0, "mkstemp should create a log file"); + if (fd < 0) { + return; + } + close(fd); + + clear_logger_env(); + setenv("LOG_FILE", path_template, 1); + setenv("LOG_LEVEL", "debug", 1); + + EXPECT_TRUE(log_init() == 0, "log_init should open a writable file"); + LOG_WARN("regular file marker"); + log_shutdown(); + + EXPECT_TRUE(file_contains(path_template, "regular file marker"), + "configured log file should contain the emitted message"); + + unlink(path_template); + clear_logger_env(); +} + +static void test_write_failure_does_not_abort(void) +{ + if (access("/dev/full", W_OK) != 0) { + fprintf(stderr, "SKIP: /dev/full is unavailable on this platform\n"); + return; + } + + clear_logger_env(); + setenv("LOG_FILE", "/dev/full", 1); + setenv("LOG_LEVEL", "debug", 1); + + EXPECT_TRUE(log_init() == 0, "log_init should open /dev/full when available"); + LOG_ERROR("write failure marker"); + LOG_ERROR("post-fallback marker"); + log_shutdown(); + + clear_logger_env(); +} + +int main(void) +{ + test_open_failure_falls_back_to_stderr(); + test_regular_file_logging_still_works(); + test_write_failure_does_not_abort(); + + if (failures != 0) { + fprintf(stderr, "%d logger error-handling test(s) failed\n", failures); + return 1; + } + + printf("logger error-handling tests passed\n"); + return 0; +}