fix(hook-augment): log under the cache dir, never at a cut-off path

Why: arming the hook-augment deadline opens its breadcrumb log with
O_CREAT. The path came from raw getenv("HOME") as
"%s/.cache/codebase-memory-mcp/logs" in 1 KiB buffers with no length
check. A HOME near 1 KiB therefore created a file at the cut-off name
(".../logs/hook-augme") on every hook call, and a longer one created a
cut-off directory. The hook also ignored CBM_CACHE_DIR, which every
other cbm component honours for its cache and logs. The index skip log
had the same defect in its CBM_INDEX_LOG override: an override longer
than 1 KiB was copied in unchecked and opened "wb", which created or
truncated the file at its cut-off prefix and reported that name as the
run's logfile.

Fix: the breadcrumb log now resolves through cbm_resolve_cache_dir()
(CBM_CACHE_DIR, else HOME, else USERPROFILE, plus the default) to
<cache_dir>/logs/hook-augment-timeouts.log. Every snprintf into the
1 KiB buffers is checked, including the one for the CBM_HOOK_TIMEOUT_LOG
override. A path that does not fit means no breadcrumb, and the logs
directory is created only for a path that fits. The hook still exits 0
(it never fails the agent's hook call) and allocates nothing new. The
CBM_INDEX_LOG override gets the same check: an override that does not
fit writes no logfile and warns index.logfile_path_too_long, and the
index still completes. With a normal HOME the log stays where it was.

Proof (dev binary, synthetic roots, isolated CBM_RUNTIME_DIR, no-op
Bash payload on stdin; "created" = find over the synthetic root minus
the pre-made HOME/cache chains):
- 980-byte HOME. Before: exit 0, plus three directories and a file at
  the cut-off name <HOME>/.cache/codebase-memory-mcp/logs/hook-augme
  (1023 bytes). After: exit 0, nothing created.
- CBM_CACHE_DIR=<root>/cache. Before: the log landed under HOME.
  After: <root>/cache/logs/hook-augment-timeouts.log.
- 1000-byte CBM_CACHE_DIR. After: exit 0, nothing created.
- Normal HOME: <HOME>/.cache/codebase-memory-mcp/logs/
  hook-augment-timeouts.log before and after.
- 1096-byte CBM_INDEX_LOG via `cli index_repository`. Before: a file
  at the 1023-byte cut-off name, reported as the logfile. After: status
  indexed, skipped_count 1, no logfile, nothing written.

Tests: RED 3x on the unfixed code for the reasons above, green with
the fix, RED again with the fix reverted:
- cli: cli_hook_augment_log_long_home_creates_no_cut_path,
  cli_hook_augment_log_honours_cache_dir, plus the positive control
  cli_hook_augment_log_default_location_unchanged (green before and
  after).
- index_resilience: index_long_log_override_writes_no_cut_path.
The fixtures sit under link-resolved temp roots: the kernel bounds the
expanded path, so under macOS's /tmp -> /private/tmp link a near-1 KiB
path can be neither created nor probed, and the bug stays hidden.

Signed-off-by: Martin Vogel <martin.vogel.tech@gmail.com>
This commit is contained in:
Martin Vogel committed 2026-09-28 19:34:10 +02:00
1 parent 1f9b4db12c
commit 7122298421
4 files changed
+395 -9

No files matched your search

+20 -8
View File
@@ -59,8 +59,9 @@
*
* Observability (#858): a fired deadline is otherwise indistinguishable from
* "no matches", so the handler first write()s a pre-formatted breadcrumb to
* ~/.cache/codebase-memory-mcp/logs/hook-augment-timeouts.log (fd and message
* prepared at arm time — only async-signal-safe write/_exit in the handler). */
* <cache_dir>/logs/hook-augment-timeouts.log (by default
* ~/.cache/codebase-memory-mcp/logs; fd and message prepared at arm time —
* only async-signal-safe write/_exit in the handler). */
#ifndef _WIN32
#define HA_DEADLINE_DEFAULT_MS 2000 /* in-process budget; see ha_deadline_ms() */
#define HA_DEADLINE_MIN_MS 50
@@ -103,20 +104,31 @@ static void ha_deadline_exit(int sig) {
_exit(0);
}
/* Whether snprintf wrote the whole string into a buffer of `cap` bytes. */
static bool ha_fits(int written, size_t cap) {
return written > 0 && (size_t)written < cap;
}
static void ha_open_crumb_log(int deadline_ms) {
const char *override = getenv("CBM_HOOK_TIMEOUT_LOG"); /* tests + power users */
char path[CBM_SZ_1K];
/* A path cut off at the buffer names some other file, and O_CREAT would
* create it. Such a path means no breadcrumb; the hook itself runs on. */
if (override && override[0]) {
snprintf(path, sizeof(path), "%s", override);
} else {
const char *home = getenv("HOME");
if (!home || !home[0]) {
if (!ha_fits(snprintf(path, sizeof(path), "%s", override), sizeof(path))) {
return;
}
} else {
/* <cache_dir>/logs, where every cbm component logs: the cache dir is
* CBM_CACHE_DIR, else HOME (then USERPROFILE) + the default. */
const char *cache = cbm_resolve_cache_dir();
char dir[CBM_SZ_1K];
snprintf(dir, sizeof(dir), "%s/.cache/codebase-memory-mcp/logs", home);
if (!cache || !ha_fits(snprintf(dir, sizeof(dir), "%s/logs", cache), sizeof(dir)) ||
!ha_fits(snprintf(path, sizeof(path), "%s/hook-augment-timeouts.log", dir),
sizeof(path))) {
return;
}
cbm_mkdir_p_ex(dir, 0755, CBM_MKDIR_FOLLOW_OWNED);
snprintf(path, sizeof(path), "%s/hook-augment-timeouts.log", dir);
}
g_ha_crumb_fd = open(path, O_WRONLY | O_CREAT | O_APPEND, 0644);
if (g_ha_crumb_fd < 0) {
+7 -1
View File
@@ -10280,7 +10280,13 @@ static bool write_skip_logfile(const char *project, const cbm_file_error_t *errs
char path[CBM_SZ_1K];
const char *override = getenv("CBM_INDEX_LOG");
if (override && override[0]) {
snprintf(path, sizeof(path), "%s", override);
/* An override that does not fit is cut off into another file's name,
* and "wb" would create or truncate that file: no logfile then. */
int written = snprintf(path, sizeof(path), "%s", override);
if (written <= 0 || (size_t)written >= sizeof(path)) {
cbm_log_warn("index.logfile_path_too_long", "source", "CBM_INDEX_LOG");
return false;
}
} else {
const char *cdir = cbm_resolve_cache_dir();
if (!cdir) {
+257
View File
@@ -14604,6 +14604,260 @@ TEST(cli_hook_augment_deadline_breadcrumb_issue858) {
#endif
}
/* ── hook-augment breadcrumb log location ──────────────────────────
* Arming the deadline opens the breadcrumb log with O_CREAT. Its path was
* "$HOME/.cache/codebase-memory-mcp/logs/hook-augment-timeouts.log" built in
* 1 KiB buffers with no length check, so a long HOME created a file at a
* cut-off name, and CBM_CACHE_DIR, which every other cbm log honours, was
* ignored. These run the real entry point in a child with a no-op Bash
* payload: the deadline is armed (the log opened), then the hook passes
* through with exit 0. POSIX only: the in-process deadline and its log are
* compiled out on Windows. */
#ifndef _WIN32
enum { HL_PATH_CAP = 1024, HL_SEGMENT = 200 };
/* Exit code of `hook-augment` run in a child with HOME = home and
* CBM_CACHE_DIR = cache_dir (unset when NULL), or -1 when it did not exit. */
static int hl_run_hook(const char *home, const char *cache_dir) {
static const char payload[] = "{\"hook_event_name\":\"PreToolUse\",\"tool_name\":\"Bash\","
"\"tool_input\":{\"command\":\"ls\"}}";
int fds[2];
if (pipe(fds) != 0) {
return -1;
}
/* Queued before the fork, so no write can meet a reader that has gone. */
ssize_t queued = write(fds[1], payload, sizeof(payload) - 1);
close(fds[1]);
if (queued != (ssize_t)(sizeof(payload) - 1)) {
close(fds[0]);
return -1;
}
fflush(NULL);
pid_t pid = fork();
if (pid == 0) {
dup2(fds[0], STDIN_FILENO);
close(fds[0]);
cbm_setenv("HOME", home, 1);
cbm_unsetenv("USERPROFILE");
cbm_unsetenv("CBM_HOOK_TIMEOUT_LOG");
if (cache_dir) {
cbm_setenv("CBM_CACHE_DIR", cache_dir, 1);
} else {
cbm_unsetenv("CBM_CACHE_DIR");
}
_exit(cbm_cmd_hook_augment(0, NULL));
}
close(fds[0]);
int status = 0;
if (pid < 0 || waitpid(pid, &status, 0) != pid || !WIFEXITED(status)) {
return -1;
}
return WEXITSTATUS(status);
}
/* A fresh synthetic root with its links resolved. The kernel bounds the
* EXPANDED path, and macOS /tmp is a link to /private/tmp: under the link a
* near-1 KiB path can be neither created nor probed, which hides the very
* cut-off file these tests look for. */
static bool hl_make_root(char *root, size_t root_sz) {
char tmpl[64];
char real[4096];
snprintf(tmpl, sizeof(tmpl), "/tmp/cbm-hooklog-XXXXXX");
if (!cbm_mkdtemp(tmpl)) {
return false;
}
if (!cbm_canonical_path(tmpl, real, sizeof(real))) {
th_rmtree(tmpl);
return false;
}
int n = snprintf(root, root_sz, "%s", real);
return n > 0 && (size_t)n < root_sz;
}
/* "<root>/hhh…/hhh…" of exactly `len` bytes, every component short of
* NAME_MAX. False when it cannot be built. */
static bool hl_long_dir(char *out, size_t out_sz, const char *root, size_t len) {
int n = snprintf(out, out_sz, "%s", root);
if (n <= 0 || (size_t)n >= len || len >= out_sz) {
return false;
}
size_t at = (size_t)n;
while (at < len) {
out[at++] = '/';
for (int seg = 0; seg < HL_SEGMENT && at < len; seg++) {
out[at++] = 'h';
}
}
out[at] = '\0';
return out[len - 1] != '/';
}
/* The first HL_PATH_CAP - 1 bytes of "<base>/<suffix>": the name the old
* unchecked 1 KiB buffer cut that path down to. */
static void hl_cut_name(char *out, const char *base, const char *suffix) {
char full[2 * HL_PATH_CAP];
snprintf(full, sizeof(full), "%s/%s", base, suffix);
snprintf(out, HL_PATH_CAP, "%.*s", HL_PATH_CAP - 1, full);
}
static bool hl_is_ancestor_or_self(const char *path, const char *of) {
size_t n = strlen(path);
return of && strncmp(of, path, n) == 0 && (of[n] == '/' || of[n] == '\0');
}
/* Entries under dir that are neither keep_a, keep_b nor one of their
* ancestors: whatever the hook created. Each is printed by its tail. */
static int hl_count_strays(const char *dir, const char *keep_a, const char *keep_b) {
cbm_dir_t *d = cbm_opendir(dir);
if (!d) {
return 0;
}
int strays = 0;
cbm_dirent_t *entry;
while ((entry = cbm_readdir(d)) != NULL) {
if (strcmp(entry->name, ".") == 0 || strcmp(entry->name, "..") == 0) {
continue;
}
char child[HL_PATH_CAP];
int n = snprintf(child, sizeof(child), "%s/%s", dir, entry->name);
bool named = n > 0 && (size_t)n < sizeof(child);
if (named &&
(hl_is_ancestor_or_self(child, keep_a) || hl_is_ancestor_or_self(child, keep_b))) {
if (entry->is_dir) {
strays += hl_count_strays(child, keep_a, keep_b);
}
continue;
}
size_t len = named ? (size_t)n : strlen(child);
printf(" stray entry: ...%s\n", child + (len > 60 ? len - 60 : 0));
strays++;
}
cbm_closedir(d);
return strays;
}
#endif
/* A HOME of ~1 KiB: the log path "<HOME>/.cache/codebase-memory-mcp/logs/
* hook-augment-timeouts.log" does not fit the buffer. The old code opened its
* cut-off prefix ".../logs/hook-augme" with O_CREAT. Nothing may be created at
* a cut path (nothing at all under the synthetic root), and the hook must
* still exit 0: it never fails the host agent's hook call. */
TEST(cli_hook_augment_log_long_home_creates_no_cut_path) {
#ifdef _WIN32
SKIP_PLATFORM("in-process deadline breadcrumb log is POSIX-only");
#else
enum { HL_HOME_LEN = 980 }; /* "<HOME>/.cache/.../logs" fits 1 KiB, the file name does not */
char root[256];
if (!hl_make_root(root, sizeof(root))) {
FAIL("synthetic root failed");
}
char home[HL_PATH_CAP];
bool built = hl_long_dir(home, sizeof(home), root, HL_HOME_LEN) && th_mkdir_p(home) == 0;
char cut[HL_PATH_CAP];
hl_cut_name(cut, home, ".cache/codebase-memory-mcp/logs/hook-augment-timeouts.log");
int rc = built ? hl_run_hook(home, NULL) : -1;
bool cut_exists = cbm_file_exists(cut);
int strays = hl_count_strays(root, home, NULL);
test_rmdir_r(root);
ASSERT_TRUE(built);
ASSERT_EQ(rc, 0);
if (cut_exists) {
printf(" log opened at the cut-off name ...%s\n", cut + strlen(cut) - 40);
}
ASSERT_FALSE(cut_exists);
ASSERT_EQ(strays, 0);
PASS();
#endif
}
/* CBM_CACHE_DIR is where every cbm log goes (<cache_dir>/logs), so the hook's
* breadcrumb goes there too, and not under HOME. A CBM_CACHE_DIR of ~1 KiB
* whose log path does not fit is no log at all: no cut-off file, no stray
* directory, and the hook still exits 0. */
TEST(cli_hook_augment_log_honours_cache_dir) {
#ifdef _WIN32
SKIP_PLATFORM("in-process deadline breadcrumb log is POSIX-only");
#else
enum { HL_CACHE_LEN = 1000 }; /* "<cache>/logs" fits 1 KiB, the file name does not */
char root[256];
if (!hl_make_root(root, sizeof(root))) {
FAIL("synthetic root failed");
}
char home[512];
char cache[512];
char expected[640];
snprintf(home, sizeof(home), "%s/home", root);
snprintf(cache, sizeof(cache), "%s/cache", root);
snprintf(expected, sizeof(expected), "%s/logs/hook-augment-timeouts.log", cache);
bool made = th_mkdir_p(home) == 0 && th_mkdir_p(cache) == 0;
/* A configured cache dir holds the log; HOME is left alone. */
int rc = made ? hl_run_hook(home, cache) : -1;
bool in_cache = cbm_file_exists(expected);
int strays = hl_count_strays(root, home, expected);
/* A configured cache dir too long for the log path: no log anywhere. */
char long_cache[HL_PATH_CAP];
char cut[HL_PATH_CAP];
bool long_built = hl_long_dir(long_cache, sizeof(long_cache), root, HL_CACHE_LEN) &&
th_mkdir_p(long_cache) == 0;
hl_cut_name(cut, long_cache, "logs/hook-augment-timeouts.log");
bool reset = th_rmtree(home) == 0 && th_rmtree(cache) == 0 && th_mkdir_p(home) == 0;
int long_rc = long_built && reset ? hl_run_hook(home, long_cache) : -1;
bool cut_exists = cbm_file_exists(cut);
int long_strays = hl_count_strays(root, home, long_cache);
test_rmdir_r(root);
ASSERT_TRUE(made);
ASSERT_EQ(rc, 0);
if (!in_cache) {
printf(" no breadcrumb log under CBM_CACHE_DIR/logs\n");
}
ASSERT_TRUE(in_cache);
ASSERT_EQ(strays, 0);
ASSERT_TRUE(long_built);
ASSERT_TRUE(reset);
ASSERT_EQ(long_rc, 0);
ASSERT_FALSE(cut_exists);
ASSERT_EQ(long_strays, 0);
PASS();
#endif
}
/* Positive control: with a normal HOME and no CBM_CACHE_DIR the breadcrumb log
* stays exactly where it always was,
* "$HOME/.cache/codebase-memory-mcp/logs/hook-augment-timeouts.log", and the
* hook creates nothing else. */
TEST(cli_hook_augment_log_default_location_unchanged) {
#ifdef _WIN32
SKIP_PLATFORM("in-process deadline breadcrumb log is POSIX-only");
#else
char root[256];
if (!hl_make_root(root, sizeof(root))) {
FAIL("synthetic root failed");
}
char home[512];
char expected[640];
snprintf(home, sizeof(home), "%s/home", root);
snprintf(expected, sizeof(expected),
"%s/.cache/codebase-memory-mcp/logs/hook-augment-timeouts.log", home);
bool made = th_mkdir_p(home) == 0;
int rc = made ? hl_run_hook(home, NULL) : -1;
bool at_default = cbm_file_exists(expected);
int strays = hl_count_strays(root, expected, NULL);
test_rmdir_r(root);
ASSERT_TRUE(made);
ASSERT_EQ(rc, 0);
ASSERT_TRUE(at_default);
ASSERT_EQ(strays, 0);
PASS();
#endif
}
TEST(cli_upsert_claude_hook_existing) {
char tmpdir[256];
snprintf(tmpdir, sizeof(tmpdir), "/tmp/cli-hook-XXXXXX");
@@ -16596,6 +16850,9 @@ SUITE(cli) {
RUN_TEST(cli_claude_exec_hooks_custom_dir_uninstall_issue1733);
RUN_TEST(cli_hook_augment_path_is_abs);
RUN_TEST(cli_hook_augment_deadline_breadcrumb_issue858);
RUN_TEST(cli_hook_augment_log_long_home_creates_no_cut_path);
RUN_TEST(cli_hook_augment_log_honours_cache_dir);
RUN_TEST(cli_hook_augment_log_default_location_unchanged);
RUN_TEST(cli_upsert_claude_hook_fresh);
RUN_TEST(cli_upsert_claude_hook_existing);
RUN_TEST(cli_tool_hooks_preserve_foreign_same_matcher);
+111
View File
@@ -274,6 +274,116 @@ TEST(index_clean_run_no_logfile) {
PASS();
}
/* INV(long-log-override): CBM_INDEX_LOG was copied into the 1 KiB logfile path
* with no length check and opened "wb", so an override longer than that
* created (or truncated) a file at its cut-off prefix and echoed the cut name
* as the run's logfile. A path that does not fit is no logfile: the index still
* completes and reports the skip, nothing is written at the cut name (its
* directory stays empty), and the response names no logfile. */
TEST(index_long_log_override_writes_no_cut_path) {
enum { RI_PATH_CAP = 1024, RI_DIR_SEGMENTS = 4, RI_SEGMENT = 200, RI_NAME = 255 };
RProj lp;
memset(&lp, 0, sizeof(lp));
snprintf(lp.tmpdir, sizeof(lp.tmpdir), "/tmp/cbm_resil_XXXXXX");
if (!cbm_mkdtemp(lp.tmpdir)) {
FAIL("mkdtemp failed");
}
rh_to_fwd_slashes(lp.tmpdir);
ri_write_text(lp.tmpdir, "good.py", "def alpha():\n return 1\n");
ri_write_big(lp.tmpdir, "big.py", (size_t)2 * 1024 * 1024); /* ~2 MiB > 1 MiB cap */
/* Outside the indexed repo: <root>/ddd…(x4) is a real directory, and the
* override adds a 255-byte file name, so the whole path runs past 1 KiB and
* its first 1023 bytes end inside the file name, in that directory. The
* root has its links resolved: the kernel bounds the EXPANDED path, and
* under macOS's /tmp -> /private/tmp link a near-1 KiB path can be neither
* created nor probed, which would hide the cut-off file. */
char tmpl[64];
char logroot[4096];
snprintf(tmpl, sizeof(tmpl), "/tmp/cbm_resil_log_XXXXXX");
if (!cbm_mkdtemp(tmpl)) {
rh_cleanup(&lp, NULL);
FAIL("mkdtemp failed");
}
if (!cbm_canonical_path(tmpl, logroot, sizeof(logroot))) {
th_rmtree(tmpl);
rh_cleanup(&lp, NULL);
FAIL("canonical log root failed");
}
rh_to_fwd_slashes(logroot);
char logdir[RI_PATH_CAP];
int root_len = snprintf(logdir, sizeof(logdir), "%s", logroot);
if (root_len <= 0 ||
(size_t)root_len + RI_DIR_SEGMENTS * (RI_SEGMENT + 1) + 2 >= sizeof(logdir)) {
th_rmtree(logroot);
rh_cleanup(&lp, NULL);
FAIL("log root too long for the fixture");
}
size_t at = (size_t)root_len;
for (int s = 0; s < RI_DIR_SEGMENTS; s++) {
logdir[at++] = '/';
memset(logdir + at, 'd', RI_SEGMENT);
at += RI_SEGMENT;
}
logdir[at] = '\0';
char name[RI_NAME + 1];
memset(name, 'x', RI_NAME);
memcpy(name, "skip-", 5);
name[RI_NAME] = '\0';
char override[2 * RI_PATH_CAP];
snprintf(override, sizeof(override), "%s/%s", logdir, name);
char cut[RI_PATH_CAP];
snprintf(cut, sizeof(cut), "%.*s", RI_PATH_CAP - 1, override);
bool made = cbm_mkdir_p(logdir, 0755) && strlen(override) >= RI_PATH_CAP &&
strlen(cut) > strlen(logdir) + 1;
cbm_setenv("CBM_MAX_FILE_BYTES", "1048576", 1); /* 1 MiB cap */
cbm_setenv("CBM_INDEX_LOG", override, 1);
char *resp = NULL;
cbm_store_t *store = made ? ri_index_capture(&lp, &resp) : NULL;
cbm_unsetenv("CBM_MAX_FILE_BYTES");
cbm_unsetenv("CBM_INDEX_LOG");
bool cut_exists = cbm_file_exists(cut);
int entries = 0;
cbm_dir_t *d = cbm_opendir(logdir);
cbm_dirent_t *entry;
while (d && (entry = cbm_readdir(d)) != NULL) {
if (strcmp(entry->name, ".") != 0 && strcmp(entry->name, "..") != 0) {
entries++;
}
}
if (d) {
cbm_closedir(d);
}
th_rmtree(logroot);
ASSERT_TRUE(made);
if (!resp) {
rh_cleanup(&lp, store);
FAIL("no MCP response");
}
yyjson_doc *doc = yyjson_read(resp, strlen(resp), 0);
ASSERT_NOT_NULL(doc);
yyjson_val *sc = yyjson_obj_get(yyjson_doc_get_root(doc), "structuredContent");
ASSERT_NOT_NULL(sc);
const char *status = yyjson_get_str(yyjson_obj_get(sc, "status"));
ASSERT_NOT_NULL(status);
ASSERT_STR_EQ("indexed", status);
ASSERT_GTE(yyjson_get_int(yyjson_obj_get(sc, "skipped_count")), 1);
if (cut_exists) {
printf(" skip log written at the cut-off name ...%s\n", cut + strlen(cut) - 40);
}
ASSERT_FALSE(cut_exists);
ASSERT_EQ(entries, 0);
ASSERT_NULL(yyjson_obj_get(sc, "logfile"));
yyjson_doc_free(doc);
free(resp);
rh_cleanup(&lp, store);
PASS();
}
/* INV(parse-partial-reported, #963): a file whose parse tree contains
* ERROR/MISSING regions (here: the preprocessor-blind #ifdef-split-brace C
* pattern) is INDEXED — not skipped — and the best-effort coverage signal
@@ -899,6 +1009,7 @@ TEST(index_relative_repo_path_canonicalized) {
SUITE(index_resilience) {
RUN_TEST(index_oversized_file_reported);
RUN_TEST(index_clean_run_no_logfile);
RUN_TEST(index_long_log_override_writes_no_cut_path);
RUN_TEST(index_parse_partial_reported);
RUN_TEST(index_parse_partial_clears_on_fix);
RUN_TEST(index_parse_unusable_names_the_range_end);