/* Host tests for libonion_platform logging: sinks, levels, rotation. */ #include "test_harness.h" #include #include #include #include #include #include #include /* --- helpers -------------------------------------------------------------- */ static char g_path[64]; static char g_crash_path[72]; static void cleanup_log_files(void) { char rotated[80]; unlink(g_path); for (unsigned i = 1; i <= ONION_LOG_DEFAULT_ROTATE_COUNT + 1; ++i) { snprintf(rotated, sizeof(rotated), "%s.%u", g_path, i); unlink(rotated); } /* Clean up artifacts produced by the previous one-generation policy. */ snprintf(rotated, sizeof(rotated), "%s.old", g_path); unlink(rotated); /* Sidecar for the cross-process rotation lock. */ snprintf(rotated, sizeof(rotated), "%s.lock", g_path); unlink(rotated); unlink(g_crash_path); /* Previous crash generation kept by the crash-sink cap. */ snprintf(rotated, sizeof(rotated), "%s.1", g_crash_path); unlink(rotated); } static void begin(const char *tag) { snprintf(g_path, sizeof(g_path), "/tmp/onion-log-test-%d", (int)getpid()); snprintf(g_crash_path, sizeof(g_crash_path), "%s-crash", g_path); cleanup_log_files(); onion_log_set_max_bytes(0); /* restore default cap */ onion_log_set_level(ONION_LOG_TRACE); onion_log_configure(tag, g_path); } static void end(void) { onion_log_configure_crash(NULL); onion_log_configure("OnionHEN", NULL); cleanup_log_files(); onion_log_set_level(ONION_LOG_INFO); onion_log_set_max_bytes(0); } static size_t read_file(const char *path, char *out, size_t out_size) { FILE *f = fopen(path, "r"); if (!f) { out[0] = '\0'; return 0; } size_t n = fread(out, 1, out_size - 1, f); fclose(f); out[n] = '\0'; return n; } static long file_size(const char *path) { struct stat st; return (stat(path, &st) == 0) ? (long)st.st_size : -1; } /* --- tests ---------------------------------------------------------------- */ static int test_log_file_sink(void) { char buf[512]; begin("HostTest"); LOG_INFO("hello %d", 42); read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "hello 42") != NULL); TEST_ASSERT_TRUE(strstr(buf, "[HostTest]") != NULL); TEST_ASSERT_TRUE(strstr(buf, "info:") != NULL); TEST_ASSERT_TRUE(strchr(buf, '\n') != NULL); end(); return 0; } /* A daemon restart must append to the previous run instead of truncating it. */ static int test_configure_appends_existing_log(void) { char buf[512]; snprintf(g_path, sizeof(g_path), "/tmp/onion-log-test-%d", (int)getpid()); cleanup_log_files(); FILE *stale = fopen(g_path, "w"); TEST_ASSERT_TRUE(stale != NULL); fputs("previous-run\n", stale); fclose(stale); onion_log_set_level(ONION_LOG_INFO); onion_log_configure("Append", g_path); LOG_INFO("current-run"); TEST_ASSERT_TRUE(file_size(g_path) >= 0); read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "previous-run") != NULL); TEST_ASSERT_TRUE(strstr(buf, "current-run") != NULL); end(); return 0; } static int test_log_configure_tag_only(void) { onion_log_configure("TagOnly", NULL); LOG_INFO("no file sink configured"); /* must not crash */ onion_log_configure("OnionHEN", NULL); return 0; } /* The runtime gate must drop records below the threshold. */ static int test_runtime_level_filters(void) { char buf[1024]; begin("Lvl"); onion_log_set_level(ONION_LOG_WARN); onion_log_write(ONION_LOG_ERROR, "keep-error"); onion_log_write(ONION_LOG_WARN, "keep-warn"); onion_log_write(ONION_LOG_INFO, "drop-info"); onion_log_write(ONION_LOG_DEBUG, "drop-debug"); LOG_INFO("drop-legacy-info"); read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "keep-error") != NULL); TEST_ASSERT_TRUE(strstr(buf, "keep-warn") != NULL); TEST_ASSERT_TRUE(strstr(buf, "drop-info") == NULL); TEST_ASSERT_TRUE(strstr(buf, "drop-debug") == NULL); TEST_ASSERT_TRUE(strstr(buf, "drop-legacy-info") == NULL); end(); return 0; } static int test_level_off_silences_everything(void) { char buf[512]; begin("Off"); onion_log_set_level(ONION_LOG_OFF); onion_log_write(ONION_LOG_ERROR, "must-not-appear"); LOG_INFO("must-not-appear-either"); read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "must-not-appear") == NULL); end(); return 0; } /* An unbounded log on a console the user cannot clean out is a real failure * mode, so the cap must actually rotate and keep a numbered backup. */ static int test_rotation_caps_size_and_keeps_backup(void) { char rotated_path[80]; char buf[2048]; begin("Rot"); onion_log_set_max_bytes(512); for (int i = 0; i < 60; i++) { onion_log_write(ONION_LOG_ERROR, "record-%02d-padding-padding-padding", i); } const long live = file_size(g_path); TEST_ASSERT_TRUE(live >= 0); TEST_ASSERT_TRUE(live <= 512); snprintf(rotated_path, sizeof(rotated_path), "%s.1", g_path); TEST_ASSERT_TRUE(file_size(rotated_path) > 0); /* Newest records live in the current file. */ read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "record-59") != NULL); end(); return 0; } /* Rotation keeps .1 as newest through .3 as the oldest retained backup. */ static int test_rotation_keeps_three_backups(void) { char rotated_path[80]; char buf[2048]; begin("Rot2"); onion_log_set_max_bytes(256); for (int i = 0; i < 200; i++) { onion_log_write(ONION_LOG_ERROR, "spam-%03d-aaaaaaaaaaaaaaaaaaaa", i); } for (unsigned i = 1; i <= ONION_LOG_DEFAULT_ROTATE_COUNT; ++i) { snprintf(rotated_path, sizeof(rotated_path), "%s.%u", g_path, i); TEST_ASSERT_TRUE(file_size(rotated_path) > 0); } snprintf(rotated_path, sizeof(rotated_path), "%s.%u", g_path, ONION_LOG_DEFAULT_ROTATE_COUNT + 1); TEST_ASSERT_TRUE(file_size(rotated_path) < 0); snprintf(rotated_path, sizeof(rotated_path), "%s.1", g_path); read_file(rotated_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "spam-000") == NULL); /* oldest rotated away */ end(); return 0; } /* Rotation must use the file's real size, including bytes appended outside * this logger instance after its descriptor was opened. */ static int test_rotation_observes_external_append(void) { char rotated_path[80]; char buf[1024]; char padding[480]; begin("External"); onion_log_set_max_bytes(512); memset(padding, 'p', sizeof(padding)); FILE *external = fopen(g_path, "ab"); TEST_ASSERT_TRUE(external != NULL); TEST_ASSERT_EQ_INT(sizeof(padding), fwrite(padding, 1, sizeof(padding), external)); fclose(external); onion_log_write(ONION_LOG_ERROR, "after-external-append"); snprintf(rotated_path, sizeof(rotated_path), "%s.1", g_path); TEST_ASSERT_TRUE(file_size(rotated_path) >= (long)sizeof(padding)); read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "after-external-append") != NULL); end(); return 0; } /* Exactly one trailing newline regardless of what the caller passed. */ static int test_single_trailing_newline(void) { char buf[512]; begin("NL"); onion_log_write(ONION_LOG_ERROR, "trailing-newline-supplied\n"); const size_t n = read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(n >= 2); TEST_ASSERT_EQ_INT('\n', buf[n - 1]); TEST_ASSERT_TRUE(buf[n - 2] != '\n'); end(); return 0; } /* Over-long records must truncate, stay terminated, and still end in \n. */ static int test_oversized_record_truncates(void) { static char big[0x2000]; char buf[0x2000]; memset(big, 'x', sizeof(big) - 1); big[sizeof(big) - 1] = '\0'; begin("Big"); onion_log_set_max_bytes(1024u * 1024u); onion_log_write(ONION_LOG_ERROR, "%s", big); const size_t n = read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(n > 0); TEST_ASSERT_EQ_INT('\n', buf[n - 1]); TEST_ASSERT_TRUE(n < sizeof(big)); /* truncated, not overflowed */ end(); return 0; } static int test_level_name_roundtrip(void) { onion_log_level lvl; TEST_ASSERT_TRUE(onion_log_level_from_name("error", &lvl)); TEST_ASSERT_EQ_INT(ONION_LOG_ERROR, lvl); TEST_ASSERT_TRUE(onion_log_level_from_name("TRACE", &lvl)); /* case-insensitive */ TEST_ASSERT_EQ_INT(ONION_LOG_TRACE, lvl); TEST_ASSERT_TRUE(onion_log_level_from_name("Off", &lvl)); TEST_ASSERT_EQ_INT(ONION_LOG_OFF, lvl); TEST_ASSERT_TRUE(!onion_log_level_from_name("verbose", &lvl)); TEST_ASSERT_TRUE(!onion_log_level_from_name("inf", &lvl)); /* prefix != match */ TEST_ASSERT_TRUE(!onion_log_level_from_name("infoo", &lvl)); TEST_ASSERT_TRUE(!onion_log_level_from_name(NULL, &lvl)); TEST_ASSERT_TRUE(strcmp("warn", onion_log_level_name(ONION_LOG_WARN)) == 0); TEST_ASSERT_TRUE(strcmp("?", onion_log_level_name((onion_log_level)99)) == 0); return 0; } static int test_set_level_clamps(void) { onion_log_set_level((onion_log_level)99); TEST_ASSERT_EQ_INT(ONION_LOG_TRACE, onion_log_get_level()); onion_log_set_level((onion_log_level)-5); TEST_ASSERT_EQ_INT(ONION_LOG_OFF, onion_log_get_level()); onion_log_set_level(ONION_LOG_INFO); return 0; } /* The crash path bypasses both gates — a fault is always worth recording. */ static int test_emergency_bypasses_level(void) { char buf[512]; begin("Emerg"); onion_log_set_level(ONION_LOG_OFF); onion_log_emergency("crash-record %d", 7); read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "crash-record 7") != NULL); end(); return 0; } /* Crash records use a dedicated append-only sink; ordinary records stay out. */ static int test_emergency_preserves_crash_sink(void) { char main_buf[512]; char crash_buf[512]; begin("CrashSink"); FILE *previous = fopen(g_crash_path, "w"); TEST_ASSERT_TRUE(previous != NULL); fputs("previous-crash\n", previous); fclose(previous); onion_log_configure_crash(g_crash_path); LOG_ERROR("ordinary-record"); onion_log_set_level(ONION_LOG_OFF); onion_log_emergency("fatal-signal %d", 11); read_file(g_path, main_buf, sizeof(main_buf)); read_file(g_crash_path, crash_buf, sizeof(crash_buf)); TEST_ASSERT_TRUE(strstr(main_buf, "ordinary-record") != NULL); TEST_ASSERT_TRUE(strstr(main_buf, "fatal-signal 11") != NULL); TEST_ASSERT_TRUE(strstr(crash_buf, "previous-crash") != NULL); TEST_ASSERT_TRUE(strstr(crash_buf, "fatal-signal 11") != NULL); TEST_ASSERT_TRUE(strstr(crash_buf, "ordinary-record") == NULL); end(); return 0; } /* Rotation is serialised across the processes that share a log path, which * needs a sidecar lock next to it. Reconfiguring drops the descriptor but the * sidecar stays behind — it carries no state beyond the kernel lock. */ static int test_rotation_creates_lock_sidecar(void) { char sidecar[80]; char buf[512]; begin("Lock"); onion_log_set_max_bytes(512); for (int i = 0; i < 60; i++) { onion_log_write(ONION_LOG_ERROR, "lock-%02d-padding-padding-padding", i); } snprintf(sidecar, sizeof(sidecar), "%s.lock", g_path); TEST_ASSERT_TRUE(file_size(sidecar) >= 0); onion_log_configure("Lock", NULL); onion_log_configure("Lock", g_path); onion_log_write(ONION_LOG_ERROR, "after-reconfigure"); read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "after-reconfigure") != NULL); end(); return 0; } /* Two payload processes append to the same path. A rotation done by one of * them must not drop the other's bytes, and the surviving writer must be able * to carry on against the live file afterwards. */ static int test_rotation_survives_second_writer(void) { static const char peer_record[] = "peer-record-from-other-process\n"; char rotated_path[80]; char buf[2048]; begin("Shared"); onion_log_set_max_bytes(512); /* Stand in for the other process with its own descriptor on the same path. */ const int peer = open(g_path, O_WRONLY | O_CREAT | O_APPEND, 0777); TEST_ASSERT_TRUE(peer >= 0); TEST_ASSERT_EQ_INT((int)sizeof(peer_record) - 1, (int)write(peer, peer_record, sizeof(peer_record) - 1)); /* Write only until the first rotation happens, so the peer record is still * within the retained generations. */ snprintf(rotated_path, sizeof(rotated_path), "%s.1", g_path); for (int i = 0; i < 64 && file_size(rotated_path) < 0; i++) { onion_log_write(ONION_LOG_ERROR, "own-%02d-padding-padding-padding", i); } TEST_ASSERT_TRUE(file_size(rotated_path) > 0); read_file(rotated_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, peer_record) != NULL); onion_log_write(ONION_LOG_ERROR, "after-rotation"); read_file(g_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "after-rotation") != NULL); close(peer); end(); return 0; } /* The crash sink has no rotation, so an oversized file must be moved aside * when a process configures it — otherwise /data fills up over time. */ static int test_crash_sink_caps_oversized_file(void) { char backup[80]; char buf[256]; static char filler[4096]; begin("CrashCap"); /* Stand in for crash files accumulated by earlier sessions. */ FILE *stale = fopen(g_crash_path, "w"); TEST_ASSERT_TRUE(stale != NULL); memset(filler, 'c', sizeof(filler)); for (unsigned i = 0; i <= ONION_LOG_DEFAULT_CRASH_MAX_BYTES / sizeof(filler); ++i) { TEST_ASSERT_EQ_INT(sizeof(filler), fwrite(filler, 1, sizeof(filler), stale)); } fclose(stale); TEST_ASSERT_TRUE(file_size(g_crash_path) > (long)ONION_LOG_DEFAULT_CRASH_MAX_BYTES); onion_log_configure_crash(g_crash_path); /* The old contents moved aside; the live file starts fresh. */ snprintf(backup, sizeof(backup), "%s.1", g_crash_path); TEST_ASSERT_TRUE(file_size(backup) > (long)ONION_LOG_DEFAULT_CRASH_MAX_BYTES); TEST_ASSERT_EQ_INT(0, (int)file_size(g_crash_path)); onion_log_set_level(ONION_LOG_OFF); onion_log_emergency("after-crash-cap"); read_file(g_crash_path, buf, sizeof(buf)); TEST_ASSERT_TRUE(strstr(buf, "after-crash-cap") != NULL); TEST_ASSERT_TRUE(strstr(buf, "cccc") == NULL); /* old bytes are not mixed in */ end(); return 0; } /* A sink whose path cannot be opened must degrade, not crash: records fall back * to klog/stdout and no file appears. This is the shape a process whose sandbox * hides the path it was handed runs into — ShellUI pointing at /data inside the * vsh sandbox is the live example. onion_log_configure() reports it on klog, * which is the only channel left once the file sink is closed. */ static int test_unopenable_sink_degrades(void) { const char *bad = "/nonexistent-onion-dir-xyz/OnionHEN.log"; onion_log_set_level(ONION_LOG_TRACE); onion_log_configure("NoSink", bad); LOG_ERROR("record with no file sink"); /* must not crash */ onion_log_emergency("emergency with no file sink"); TEST_ASSERT_TRUE(file_size(bad) < 0); /* nothing was created */ onion_log_configure("OnionHEN", NULL); onion_log_set_level(ONION_LOG_INFO); return 0; } int test_platform_log_suite(void) { int failures = 0; failures += onion_test_run("log.file_sink", test_log_file_sink); failures += onion_test_run("log.configure_appends", test_configure_appends_existing_log); failures += onion_test_run("log.configure_tag_only", test_log_configure_tag_only); failures += onion_test_run("log.runtime_level_filters", test_runtime_level_filters); failures += onion_test_run("log.level_off", test_level_off_silences_everything); failures += onion_test_run("log.rotation_caps_size", test_rotation_caps_size_and_keeps_backup); failures += onion_test_run("log.rotation_three_backups", test_rotation_keeps_three_backups); failures += onion_test_run("log.rotation_external_append", test_rotation_observes_external_append); failures += onion_test_run("log.rotation_lock_sidecar", test_rotation_creates_lock_sidecar); failures += onion_test_run("log.rotation_second_writer", test_rotation_survives_second_writer); failures += onion_test_run("log.single_newline", test_single_trailing_newline); failures += onion_test_run("log.oversized_truncates", test_oversized_record_truncates); failures += onion_test_run("log.level_name_roundtrip", test_level_name_roundtrip); failures += onion_test_run("log.set_level_clamps", test_set_level_clamps); failures += onion_test_run("log.emergency_bypasses_level", test_emergency_bypasses_level); failures += onion_test_run("log.emergency_preserves_crash_sink", test_emergency_preserves_crash_sink); failures += onion_test_run("log.crash_sink_caps_oversized", test_crash_sink_caps_oversized_file); failures += onion_test_run("log.unopenable_sink_degrades", test_unopenable_sink_degrades); return failures; }