Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 9 additions & 0 deletions docs/OPERATIONS.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
24 changes: 15 additions & 9 deletions frailbox/include/logger.h
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
47 changes: 44 additions & 3 deletions frailbox/src/logger.c
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down Expand Up @@ -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();

Expand Down Expand Up @@ -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) {
Expand All @@ -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);
Expand Down Expand Up @@ -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);
Expand All @@ -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
Expand Down
188 changes: 188 additions & 0 deletions frailbox/tests/test_logger_shutdown.c
Original file line number Diff line number Diff line change
@@ -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 <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <assert.h>
#include <pthread.h>
#include <unistd.h>

#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;
}