diff --git a/diagnostic/build-fa564fee.json b/diagnostic/build-fa564fee.json new file mode 100644 index 000000000..1d6450d0e --- /dev/null +++ b/diagnostic/build-fa564fee.json @@ -0,0 +1,87 @@ +{ + "generated_at": "2026-06-27T02:49:23.678788+00:00", + "commit": "fa564fee", + "diagnostic_logd": "diagnostic\\build-fa564fee.logd", + "diagnostic_logd_error": null, + "message_blocker": null, + "chunked": false, + "chunk_size_bytes": null, + "password": "8975709d4cc274107416", + "decrypt_command": "encryptly unpack diagnostic\\build-fa564fee.logd --password 8975709d4cc274107416", + "total_modules": 10, + "passed": 0, + "failed": 10, + "modules": [ + { + "name": "backend", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "frontend", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "market", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "frailbox", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "engine", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "compliance", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "v2-market-stream", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "nfc-scanner", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "openapi-haskell", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + }, + { + "name": "openapi-tools", + "status": "FAIL", + "elapsed_seconds": 0, + "artifact": null, + "output": "Command not found: [WinError 2] El sistema no puede encontrar el archivo especificado" + } + ], + "pr_note": "Include the encrypted diagnostic logd artifact(s): diagnostic\\build-fa564fee.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-fa564fee.logd b/diagnostic/build-fa564fee.logd new file mode 100644 index 000000000..5a93f841b Binary files /dev/null and b/diagnostic/build-fa564fee.logd differ diff --git a/docs/OPERATIONS.md b/docs/OPERATIONS.md index 58642e7b9..7e4d61431 100644 --- a/docs/OPERATIONS.md +++ b/docs/OPERATIONS.md @@ -15,6 +15,26 @@ ## Monitoring +### Frailbox Legacy Logger Fallbacks + +The legacy frailbox logger keeps stderr as the guaranteed fallback sink. When +`LOG_FILE` cannot be opened, the logger reports the failed operation, path, +`errno` text, and a short likely-cause hint before continuing on stderr. When a +configured log file opens successfully but later fails during `fputs` or +`fflush`, the logger closes that file, switches to stderr, reports the write +failure, and replays the current log line to stderr so the triggering message is +not lost. + +The focused logger fallback harness does not require external services: + +```bash +cd frailbox +make logger-error-test +``` + +The harness verifies the missing-path open fallback and, on Linux hosts with +`/dev/full`, the write-failure fallback path. + ### Health Check Endpoints Each service exposes a health check endpoint: diff --git a/frailbox/Makefile b/frailbox/Makefile index d4383d853..a1c361866 100644 --- a/frailbox/Makefile +++ b/frailbox/Makefile @@ -37,7 +37,11 @@ distclean: clean test: $(TARGET) ./$(TARGET) --sandbox-type seccomp --memory-limit 64 --verbose +logger-error-test: + $(CC) $(CFLAGS) -I$(INCDIR) src/logger.c tests/test_logger_errors.c -o $(BUILDDIR)/test_logger_errors -lpthread + ./$(BUILDDIR)/test_logger_errors + 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 f1a7aa1a3..bb0635ead 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 for the active log file. This is only used in diagnostics when a + * file operation fails and the logger has to fall back to stderr. + */ +static char g_log_file_path[1024] = "stderr"; + /** * Whether to include timestamps in log output. * This can be disabled for performance-critical logging paths. @@ -181,6 +187,100 @@ static pid_t g_pid = 0; /* INTERNAL HELPERS */ /* ------------------------------------------------------------------ */ +static const char *logger_errno_hint(int error_code) +{ + switch (error_code) { + case EACCES: + return "permission denied"; + case ENOENT: + return "path or parent directory does not exist"; + case EISDIR: + return "path is a directory"; + case ENOSPC: + return "device is full"; + case EROFS: + return "filesystem is read-only"; + case EIO: + return "I/O error"; + default: + return "see errno for details"; + } +} + +static void set_log_path_unlocked(const char *path) +{ + const char *source = (path != NULL && path[0] != '\0') ? path : "stderr"; + strncpy(g_log_file_path, source, sizeof(g_log_file_path) - 1); + g_log_file_path[sizeof(g_log_file_path) - 1] = '\0'; +} + +static void close_log_file_unlocked(void) +{ + if (g_log_file != NULL && g_log_file != stderr) { + if (fflush(g_log_file) == EOF) { + fprintf(stderr, + "Legacy logger: failed to flush log file '%s' before close: %s (%s)\n", + g_log_file_path, strerror(errno), logger_errno_hint(errno)); + clearerr(g_log_file); + } + if (fclose(g_log_file) == EOF) { + fprintf(stderr, + "Legacy logger: failed to close log file '%s': %s (%s)\n", + g_log_file_path, strerror(errno), logger_errno_hint(errno)); + } + } + g_log_file = stderr; + set_log_path_unlocked("stderr"); +} + +static void fallback_to_stderr_unlocked(const char *operation, + const char *path, + int error_code) +{ + const char *target = (path != NULL && path[0] != '\0') ? path : g_log_file_path; + + fprintf(stderr, + "Legacy logger: %s failed for log file '%s': %s (%s); falling back to stderr.\n", + operation, target, strerror(error_code), logger_errno_hint(error_code)); + + if (g_log_file != NULL && g_log_file != stderr) { + clearerr(g_log_file); + fclose(g_log_file); + } + g_log_file = stderr; + set_log_path_unlocked("stderr"); +} + +static int write_log_line_unlocked(const char *buffer) +{ + FILE *target = (g_log_file != NULL) ? g_log_file : stderr; + + errno = 0; + if (fputs(buffer, target) == EOF || fflush(target) == EOF) { + int saved_errno = (errno != 0) ? errno : EIO; + + if (target != stderr) { + 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'; + + fallback_to_stderr_unlocked("write", failed_path, saved_errno); + + errno = 0; + if (fputs(buffer, stderr) == EOF || fflush(stderr) == EOF) { + clearerr(stderr); + return -1; + } + return 0; + } + + clearerr(stderr); + return -1; + } + + return 0; +} + /** * Gets the current time as a struct tm. Thread-safe. * Uses localtime_r() which is POSIX.1-2001 compliant. @@ -354,6 +454,13 @@ int log_init(void) /* Cache PID */ g_pid = getpid(); + g_log_level = DEFAULT_LOG_LEVEL; + g_include_timestamps = 1; + g_include_source_info = 0; + strncpy(g_module_name, "frailbox", sizeof(g_module_name) - 1); + g_module_name[sizeof(g_module_name) - 1] = '\0'; + + close_log_file_unlocked(); /* Read environment variables */ const char *env_level = getenv("LOG_LEVEL"); @@ -379,13 +486,14 @@ int log_init(void) if (env_log_file != NULL && strlen(env_log_file) > 0) { 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)); - /* Fall back to stderr */ - g_log_file = stderr; + int saved_errno = (errno != 0) ? errno : EIO; + fallback_to_stderr_unlocked("open", env_log_file, saved_errno); + } else { + set_log_path_unlocked(env_log_file); } } else { g_log_file = stderr; + set_log_path_unlocked("stderr"); } const char *env_module = getenv("LOG_MODULE"); @@ -526,13 +634,7 @@ void log_message(int level, const char *file, int line, const char *fmt, ...) } /* Write to output */ - if (g_log_file != NULL) { - fputs(buffer, g_log_file); - fflush(g_log_file); - } else { - fputs(buffer, stderr); - fflush(stderr); - } + (void)write_log_line_unlocked(buffer); pthread_mutex_unlock(&log_mutex); @@ -550,11 +652,7 @@ 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); - g_log_file = NULL; - } + close_log_file_unlocked(); g_log_level = LOG_LEVEL_NONE; @@ -596,7 +694,10 @@ int log_dump_ring_buffer(int fd) written += snprintf(ring_buf + written, sizeof(ring_buf) - written, "=== END RING BUFFER DUMP ===\n"); ssize_t _written = write(fd, ring_buf, written); - (void)_written; // suppress unused-result warning. the ring buffer dump is best-effort. + if (_written < 0) { + pthread_mutex_unlock(&g_ring_buffer.ring_mutex); + return -1; + } pthread_mutex_unlock(&g_ring_buffer.ring_mutex); return count; diff --git a/frailbox/tests/test_logger_errors.c b/frailbox/tests/test_logger_errors.c new file mode 100644 index 000000000..b8a76be88 --- /dev/null +++ b/frailbox/tests/test_logger_errors.c @@ -0,0 +1,105 @@ +#define _GNU_SOURCE + +#include "../include/logger.h" + +#include +#include +#include +#include +#include +#include + +struct stderr_capture { + int saved_fd; + char path[256]; +}; + +static void capture_stderr_begin(struct stderr_capture *capture) +{ + snprintf(capture->path, sizeof(capture->path), + "/tmp/frailbox-logger-errors-%ld-XXXXXX", (long)getpid()); + + int fd = mkstemp(capture->path); + assert(fd >= 0); + + fflush(stderr); + capture->saved_fd = dup(STDERR_FILENO); + assert(capture->saved_fd >= 0); + assert(dup2(fd, STDERR_FILENO) >= 0); + close(fd); +} + +static char *capture_stderr_end(struct stderr_capture *capture) +{ + fflush(stderr); + assert(dup2(capture->saved_fd, STDERR_FILENO) >= 0); + close(capture->saved_fd); + + FILE *fp = fopen(capture->path, "rb"); + assert(fp != NULL); + assert(fseek(fp, 0, SEEK_END) == 0); + long size = ftell(fp); + assert(size >= 0); + rewind(fp); + + char *data = calloc((size_t)size + 1, 1); + assert(data != NULL); + assert(fread(data, 1, (size_t)size, fp) == (size_t)size); + fclose(fp); + unlink(capture->path); + return data; +} + +static void configure_logger(const char *log_file) +{ + setenv("LOG_LEVEL", "debug", 1); + setenv("LOG_NO_TIMESTAMPS", "1", 1); + setenv("LOG_MODULE", "logger-test", 1); + setenv("LOG_FILE", log_file, 1); +} + +static void test_open_failure_falls_back_to_stderr(void) +{ + struct stderr_capture capture; + capture_stderr_begin(&capture); + + configure_logger("/tmp/frailbox-missing-directory/logger.log"); + assert(log_init() == 0); + LOG_ERROR("open fallback message"); + log_shutdown(); + + char *stderr_text = capture_stderr_end(&capture); + assert(strstr(stderr_text, "open failed for log file") != NULL); + assert(strstr(stderr_text, "falling back to stderr") != NULL); + assert(strstr(stderr_text, "open fallback message") != NULL); + free(stderr_text); +} + +static void test_write_failure_falls_back_to_stderr(void) +{ + if (access("/dev/full", W_OK) != 0) { + fprintf(stderr, "skipping /dev/full write fallback test on this platform\n"); + return; + } + + struct stderr_capture capture; + capture_stderr_begin(&capture); + + configure_logger("/dev/full"); + assert(log_init() == 0); + LOG_ERROR("write fallback message"); + log_shutdown(); + + char *stderr_text = capture_stderr_end(&capture); + assert(strstr(stderr_text, "write failed for log file") != NULL); + assert(strstr(stderr_text, "falling back to stderr") != NULL); + assert(strstr(stderr_text, "write fallback message") != NULL); + free(stderr_text); +} + +int main(void) +{ + test_open_failure_falls_back_to_stderr(); + test_write_failure_falls_back_to_stderr(); + return 0; +}