From 174efedfba37164e9490a20f19ed8dd8247c95e6 Mon Sep 17 00:00:00 2001 From: Saiaaax Date: Thu, 25 Jun 2026 11:24:33 +0800 Subject: [PATCH] [0 BOUNTY] [C] Define logger behavior after shutdown - Add g_shutdown flag to track shutdown state - log_message() silently drops messages after shutdown - Add log_is_shutdown() to query shutdown state (thread-safe) - log_init() resets g_shutdown for re-initialization - log_shutdown() is idempotent (safe to call multiple times) - 5-test harness covering all acceptance criteria Closes #15 --- docs/OPERATIONS.md | 9 ++ frailbox/include/logger.h | 24 ++-- frailbox/src/logger.c | 47 ++++++- frailbox/tests/test_logger_shutdown.c | 188 ++++++++++++++++++++++++++ 4 files changed, 256 insertions(+), 12 deletions(-) create mode 100644 frailbox/tests/test_logger_shutdown.c diff --git a/docs/OPERATIONS.md b/docs/OPERATIONS.md index 58642e7b9..280b5643f 100644 --- a/docs/OPERATIONS.md +++ b/docs/OPERATIONS.md @@ -310,3 +310,12 @@ Audit logs are retained for 365 days and include: 2. Update Kubernetes secret: `kubectl create secret tls tot-tls --cert=new.crt --key=new.key -n tent-production --dry-run=client -o yaml | kubectl apply -f -` 3. Restart services: `kubectl rollout restart deployment -n tent-production` 4. Verify new certificate: `openssl s_client -connect api.example.com:443 -servername api.example.com` + +## Logger Post-Shutdown Behavior + +The legacy logger now has defined post-shutdown behavior. After `log_shutdown()`: +- All `log_message()` calls are silently dropped (no crash, no write to freed resources) +- `log_is_shutdown()` returns 1 after shutdown, 0 after re-initialization +- Calling `log_shutdown()` multiple times is safe (idempotent) +- Calling `log_init()` after shutdown re-enables logging +- The shutdown state is thread-safe diff --git a/frailbox/include/logger.h b/frailbox/include/logger.h index b9e2248c5..c1074a954 100644 --- a/frailbox/include/logger.h +++ b/frailbox/include/logger.h @@ -252,18 +252,24 @@ void log_message(int level, const char *file, int line, const char *fmt, ...); /** * Shutdown the legacy logging subsystem. - * Flushes and closes the log file. After shutdown, log messages - * will go to stderr. Calling shutdown multiple times is safe. - * Do NOT call any log_* functions after shutdown unless you call - * log_init() first. The behavior is undefined but usually results - * in a segmentation fault. Actually, it results in a write to - * stderr because the fallback path uses stderr. But don't rely - * on this behavior - it might change in the next refactor. - * - * TODO: Make the post-shutdown behavior defined (write to /dev/null). + * Flushes and closes the log file. After shutdown, all log_message() + * calls are silently dropped — no output is produced and no freed + * resources are accessed. This behavior is guaranteed and thread-safe. + * + * To resume logging after shutdown, call log_init() again. + * Calling shutdown multiple times is safe (idempotent). */ void log_shutdown(void); +/** + * Check whether the logging subsystem has been shut down. + * Thread-safe. Returns 1 if log_shutdown() has been called + * (and log_init() has not been called since), 0 otherwise. + * + * @return 1 if shut down, 0 if active + */ +int log_is_shutdown(void); + /** * Dump the ring buffer contents to a file descriptor. * The ring buffer stores the last N log entries for crash reporting. diff --git a/frailbox/src/logger.c b/frailbox/src/logger.c index f1a7aa1a3..fb85676e9 100644 --- a/frailbox/src/logger.c +++ b/frailbox/src/logger.c @@ -129,6 +129,14 @@ static int g_log_level = DEFAULT_LOG_LEVEL; */ static FILE *g_log_file = NULL; +/** + * Whether the logger has been shut down. + * After shutdown, log_message() silently drops messages rather than + * writing through freed/closed resources. This flag is checked + * under the log_mutex for thread safety. + */ +static int g_shutdown = 0; + /** * Whether to include timestamps in log output. * This can be disabled for performance-critical logging paths. @@ -352,6 +360,9 @@ int log_init(void) { pthread_mutex_lock(&log_mutex); + /* Reset shutdown state on re-initialization */ + g_shutdown = 0; + /* Cache PID */ g_pid = getpid(); @@ -464,11 +475,23 @@ int log_get_level(void) */ void log_message(int level, const char *file, int line, const char *fmt, ...) { - /* Check log level */ + /* Check log level first (fast path, no lock needed for read) */ if (level > g_log_level) { return; } + /* Check shutdown state under mutex. + * After shutdown, messages are silently dropped. This is the + * documented post-shutdown behavior: no crash, no write to + * freed resources, no output at all. Callers that need to + * capture post-shutdown messages should use a custom sink + * registered before shutdown. */ + pthread_mutex_lock(&log_mutex); + if (g_shutdown) { + pthread_mutex_unlock(&log_mutex); + return; + } + /* Determine level string */ const char *level_str; switch (level) { @@ -485,8 +508,7 @@ void log_message(int level, const char *file, int line, const char *fmt, ...) char buffer[MAX_LOG_LINE]; int offset = 0; - /* Format prefix */ - pthread_mutex_lock(&log_mutex); + /* Format prefix (mutex already held) */ offset = format_log_prefix(buffer, MAX_LOG_LINE, level_str, file, line); if (offset < 0 || offset >= MAX_LOG_LINE) { pthread_mutex_unlock(&log_mutex); @@ -550,6 +572,9 @@ void log_shutdown(void) { pthread_mutex_lock(&log_mutex); + /* Mark as shutdown so log_message() drops messages safely */ + g_shutdown = 1; + if (g_log_file != NULL && g_log_file != stderr) { fflush(g_log_file); fclose(g_log_file); @@ -560,9 +585,25 @@ void log_shutdown(void) pthread_mutex_unlock(&log_mutex); + /* This final message goes to stderr directly, bypassing the + * now-shutdown logger. This is intentional — the shutdown + * confirmation must be visible even though the logger is off. */ fprintf(stderr, "Legacy logging subsystem shut down.\n"); } +/** + * Check whether the logging subsystem has been shut down. + * Thread-safe. Returns 1 after log_shutdown(), 0 after log_init(). + */ +int log_is_shutdown(void) +{ + int state; + pthread_mutex_lock(&log_mutex); + state = g_shutdown; + pthread_mutex_unlock(&log_mutex); + return state; +} + /** * Dumps the ring buffer contents to a file descriptor. * This is called by the crash signal handler to include recent diff --git a/frailbox/tests/test_logger_shutdown.c b/frailbox/tests/test_logger_shutdown.c new file mode 100644 index 000000000..9a7c16ca0 --- /dev/null +++ b/frailbox/tests/test_logger_shutdown.c @@ -0,0 +1,188 @@ +/** + * @file test_logger_shutdown.c + * @brief Test harness for logger post-shutdown behavior. + * + * Compile: + * gcc -DTEST_LOGGER_SHUTDOWN -I../include ../src/logger.c -o test_logger_shutdown -lpthread + * + * Run: + * ./test_logger_shutdown + * + * Tests: + * 1. log-before-shutdown — messages appear before shutdown + * 2. log-after-shutdown — messages are silently dropped after shutdown + * 3. repeated-shutdown — calling shutdown twice is safe + * 4. concurrent-shutdown — log and shutdown from threads simultaneously + */ + +#include +#include +#include +#include +#include +#include + +#include "../include/logger.h" + +/* ------------------------------------------------------------------ */ +/* HELPERS */ +/* ------------------------------------------------------------------ */ + +static int test_count = 0; +static int pass_count = 0; + +#define TEST_ASSERT(cond, msg) do { \ + test_count++; \ + if (cond) { \ + pass_count++; \ + printf(" PASS: %s\n", msg); \ + } else { \ + printf(" FAIL: %s (line %d)\n", msg, __LINE__); \ + } \ +} while(0) + +/* ------------------------------------------------------------------ */ +/* TEST: Log before shutdown */ +/* ------------------------------------------------------------------ */ +static void test_log_before_shutdown(void) +{ + printf("\n[TEST] Log before shutdown\n"); + log_init(); + TEST_ASSERT(log_is_shutdown() == 0, "logger is not shut down after init"); + + /* Messages should be produced — we can't easily capture stderr in + * this harness, but we verify the logger doesn't crash. */ + LOG_INFO("test: message before shutdown"); + LOG_ERROR("test: error before shutdown"); + TEST_ASSERT(1, "log messages before shutdown did not crash"); + + log_shutdown(); +} + +/* ------------------------------------------------------------------ */ +/* TEST: Log after shutdown */ +/* ------------------------------------------------------------------ */ +static void test_log_after_shutdown(void) +{ + printf("\n[TEST] Log after shutdown\n"); + log_init(); + log_shutdown(); + TEST_ASSERT(log_is_shutdown() == 1, "logger is shut down after shutdown call"); + + /* These should be silently dropped — no crash, no write to freed resources */ + LOG_ERROR("test: this should be silently dropped"); + LOG_INFO("test: this too should be silently dropped"); + LOG_DEBUG("test: and this"); + TEST_ASSERT(1, "log messages after shutdown did not crash"); + + /* log_message direct call */ + log_message(LOG_LEVEL_ERROR, __FILE__, __LINE__, + "direct call after shutdown — should be dropped"); + TEST_ASSERT(1, "direct log_message after shutdown did not crash"); +} + +/* ------------------------------------------------------------------ */ +/* TEST: Repeated shutdown */ +/* ------------------------------------------------------------------ */ +static void test_repeated_shutdown(void) +{ + printf("\n[TEST] Repeated shutdown\n"); + log_init(); + LOG_INFO("test: before first shutdown"); + + log_shutdown(); + TEST_ASSERT(log_is_shutdown() == 1, "shut down after first call"); + + /* Second shutdown should be safe */ + log_shutdown(); + TEST_ASSERT(log_is_shutdown() == 1, "still shut down after second call"); + + /* Log after repeated shutdown */ + LOG_ERROR("test: after repeated shutdown"); + TEST_ASSERT(1, "log after repeated shutdown did not crash"); +} + +/* ------------------------------------------------------------------ */ +/* TEST: Reinitialize after shutdown */ +/* ------------------------------------------------------------------ */ +static void test_reinit_after_shutdown(void) +{ + printf("\n[TEST] Reinitialize after shutdown\n"); + log_init(); + LOG_INFO("test: first init"); + + log_shutdown(); + TEST_ASSERT(log_is_shutdown() == 1, "shut down"); + + /* Re-init should clear shutdown state */ + log_init(); + TEST_ASSERT(log_is_shutdown() == 0, "not shut down after re-init"); + + LOG_INFO("test: after re-init"); + TEST_ASSERT(1, "log after re-init did not crash"); + + log_shutdown(); +} + +/* ------------------------------------------------------------------ */ +/* TEST: Concurrent log and shutdown */ +/* ------------------------------------------------------------------ */ + +static volatile int concurrent_stop = 0; + +static void *concurrent_logger_thread(void *arg) +{ + (void)arg; + while (!concurrent_stop) { + LOG_INFO("concurrent thread logging"); + } + return NULL; +} + +static void test_concurrent_log_shutdown(void) +{ + printf("\n[TEST] Concurrent log and shutdown\n"); + + log_init(); + + pthread_t threads[4]; + for (int i = 0; i < 4; i++) { + pthread_create(&threads[i], NULL, concurrent_logger_thread, NULL); + } + + /* Let threads log for a bit */ + usleep(50000); /* 50ms */ + + /* Shutdown while threads are still logging */ + log_shutdown(); + TEST_ASSERT(log_is_shutdown() == 1, "shut down while threads logging"); + + /* Signal threads to stop */ + concurrent_stop = 1; + + for (int i = 0; i < 4; i++) { + pthread_join(threads[i], NULL); + } + + TEST_ASSERT(1, "concurrent log + shutdown did not crash"); + concurrent_stop = 0; +} + +/* ------------------------------------------------------------------ */ +/* MAIN */ +/* ------------------------------------------------------------------ */ + +int main(void) +{ + printf("=== Logger Shutdown Behavior Tests ===\n"); + + test_log_before_shutdown(); + test_log_after_shutdown(); + test_repeated_shutdown(); + test_reinit_after_shutdown(); + test_concurrent_log_shutdown(); + + printf("\n=== Results: %d/%d passed ===\n", pass_count, test_count); + + return (pass_count == test_count) ? 0 : 1; +}