From 460ebefc87df4dd5142bdc339702edd4feec4696 Mon Sep 17 00:00:00 2001 From: juan Carlos Estrada Montoya Date: Fri, 4 Sep 2026 14:20:11 -0500 Subject: [PATCH] fix(graph-buffer): log why an atomic publish failed instead of a successful dump MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit cbm_gbuf_dump_to_sqlite() emitted gbuf.dump regardless of the writer's result, so a run that published nothing still logged node and edge counts as if it had worked, and the failure reached the user only as the generic "Pipeline failed. Check repo_path exists and contains source files." The writer's temp -> final rename in publish_writer_output() returned a bare ERR_WRITE_FAILED. #1628 taught cbm_rename_replace() to translate the platform error into errno so callers could report why, and wired up the stage -> final rename in pipeline.c. This is the other rename on that path, and it is the one that runs first. Preserve errno across the cleanup in every publish error branch. That includes cbm_writer_open(), where the cleanup unlinks a file that was never created: without the save it leaves ENOENT behind, so a directory that denied the create is reported as a missing path — the #1620 case, stated wrongly. Read the value in graph_buffer.c before the profiling macro can clobber it, and report gbuf.dump_failed with the return code and that errno. A sticky append failure clears errno rather than attach a reason it does not have, and the field is omitted when there is none. No logging is added inside internal/cbm/, which has none today. Tests cover both halves: the dump reports a failure instead of a summary, the writer names its truncation reason, and the publish rename's errno survives a cleanup that itself fails. Refs #1620, #2001. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_012FxkVF773gDGNmBmsLnzN7 Signed-off-by: juan Carlos Estrada Montoya --- internal/cbm/sqlite_writer.c | 26 +++++++++ src/graph_buffer/graph_buffer.c | 38 ++++++++++++- tests/test_graph_buffer.c | 73 +++++++++++++++++++++++++ tests/test_sqlite_writer.c | 97 +++++++++++++++++++++++++++++++++ 4 files changed, 233 insertions(+), 1 deletion(-) diff --git a/internal/cbm/sqlite_writer.c b/internal/cbm/sqlite_writer.c index 55ab937d48..da8aba06c5 100644 --- a/internal/cbm/sqlite_writer.c +++ b/internal/cbm/sqlite_writer.c @@ -28,6 +28,7 @@ #include #include #include +#include #ifdef _WIN32 #include @@ -1777,6 +1778,10 @@ static int sync_writer_output(FILE *fp) { } static int discard_writer_output(write_db_ctx_t *w, int rc) { + /* Cleanup runs after the failure that brought us here, and a library + * call may set errno even when it succeeds. Carry the reason across it + * so the caller can report WHY the publish failed. */ + int failure_errno = errno; if (w->fp) { (void)fclose(w->fp); w->fp = NULL; @@ -1784,6 +1789,7 @@ static int discard_writer_output(write_db_ctx_t *w, int rc) { if (w->temp_path[0]) { (void)cbm_unlink(w->temp_path); } + errno = failure_errno; return rc; } @@ -1792,10 +1798,12 @@ static int publish_writer_output(write_db_ctx_t *w) { return discard_writer_output(w, ERR_WRITE_FAILED); } if (fclose(w->fp) != 0) { + int failure_errno = errno; w->fp = NULL; if (w->temp_path[0]) { (void)cbm_unlink(w->temp_path); } + errno = failure_errno; return ERR_WRITE_FAILED; } w->fp = NULL; @@ -1803,7 +1811,12 @@ static int publish_writer_output(write_db_ctx_t *w) { return 0; } if (cbm_rename_replace(w->temp_path, w->final_path) != 0) { + /* cbm_rename_replace translated the platform error into errno so the + * caller can say what denied the publish (#1620). Preserve it across + * the cleanup unlink. */ + int rename_errno = errno; (void)cbm_unlink(w->temp_path); + errno = rename_errno; return ERR_WRITE_FAILED; } /* Sidecars are removed only after the replacement succeeds. On POSIX, @@ -2303,13 +2316,22 @@ cbm_db_writer_t *cbm_writer_open(const char *path) { int n = snprintf(w->wc.final_path, sizeof(w->wc.final_path), "%s", path); if (n < 0 || (size_t)n >= sizeof(w->wc.final_path) || make_writer_temp_path(path, w, w->wc.temp_path, sizeof(w->wc.temp_path)) != 0) { + /* Both conditions are truncation and neither sets errno; name the + * reason rather than let the caller report a stale one. */ free(w); + errno = ENAMETOOLONG; return NULL; } FILE *fp = cbm_fopen(w->wc.temp_path, "wb"); if (!fp) { + /* The cleanup below unlinks a file that was never created, so it + * fails and leaves ENOENT behind — which reads as a missing path + * when the real answer is that the directory refused the create. + * That is the #1620 case, so carry the open's reason across it. */ + int open_errno = errno; (void)cbm_unlink(w->wc.temp_path); free(w); + errno = open_errno; return NULL; } w->wc.fp = fp; @@ -2377,6 +2399,10 @@ int cbm_writer_finalize(cbm_db_writer_t *w, const char *project, const char *roo write_db_ctx_t wc = w->wc; /* value copy survives free(w) */ free(w); if (err != 0) { + /* A sticky append failure: errno belongs to whatever call failed + * many calls ago, not to the publish. Clear it so the caller does + * not attach a reason this path does not have. */ + errno = 0; return discard_writer_output(&wc, err); } return write_db_after_nodes(&wc, nodes_root); diff --git a/src/graph_buffer/graph_buffer.c b/src/graph_buffer/graph_buffer.c index 24553657df..e55eb28f02 100644 --- a/src/graph_buffer/graph_buffer.c +++ b/src/graph_buffer/graph_buffer.c @@ -39,6 +39,7 @@ enum { #include "foundation/mem_core.h" #include +#include #include #include // int64_t #include @@ -1841,6 +1842,32 @@ static void log_dump_summary(int node_count, int edge_count) { cbm_log_info("gbuf.dump", "nodes", b1, "edges", b2); } +/* A dump that published nothing gets exactly one signature in the log. + * Without it the writer's return code is the only evidence, and it reaches + * the user as a generic pipeline failure that blames their repository + * (#1620, #2001). + * + * failure_errno is read by the caller at the point of failure: the value is + * only meaningful before the next library call. Zero means the failure did + * not originate at the publish boundary — an append that failed many calls + * earlier — and the field is omitted rather than claim a reason this record + * does not have. */ +static void log_dump_failed(int rc, int failure_errno, int node_count, int edge_count) { + char b1[CBM_SZ_16]; + char b3[CBM_SZ_16]; + char b4[CBM_SZ_16]; + snprintf(b1, sizeof(b1), "%d", rc); + snprintf(b3, sizeof(b3), "%d", node_count); + snprintf(b4, sizeof(b4), "%d", edge_count); + if (failure_errno == 0) { + cbm_log_error("gbuf.dump_failed", "rc", b1, "nodes", b3, "edges", b4); + return; + } + char b2[CBM_SZ_16]; + snprintf(b2, sizeof(b2), "%d", failure_errno); + cbm_log_error("gbuf.dump_failed", "rc", b1, "errno", b2, "nodes", b3, "edges", b4); +} + static void free_dump_resources(char **url_paths, char **local_names, int edge_count, CBMDumpEdge *dump_edges, CBMDumpNode *dump_nodes, int64_t *temp_to_final) { @@ -1896,6 +1923,7 @@ int cbm_gbuf_dump_to_sqlite(cbm_gbuf_t *gb, const char *path) { int64_t max_temp_id = gb->next_id; int64_t *temp_to_final = cbm_calloc(CBM_MEM_CLASS_DUMP, (size_t)max_temp_id * sizeof(int64_t)); if (!temp_to_final) { + log_dump_failed(CBM_NOT_FOUND, errno, 0, 0); return CBM_NOT_FOUND; } @@ -1926,6 +1954,7 @@ int cbm_gbuf_dump_to_sqlite(cbm_gbuf_t *gb, const char *path) { * uninitialized budget from ever triggering the free). */ cbm_db_writer_t *w = cbm_writer_open(path); if (!w) { + log_dump_failed(CBM_NOT_FOUND, errno, node_idx, 0); cbm_free(CBM_MEM_CLASS_DUMP, src_nodes); cbm_free(CBM_MEM_CLASS_DUMP, dump_nodes); cbm_free(CBM_MEM_CLASS_DUMP, temp_to_final); @@ -1980,12 +2009,19 @@ int cbm_gbuf_dump_to_sqlite(cbm_gbuf_t *gb, const char *path) { int frc = cbm_writer_finalize(w, gb->project, gb->root_path, indexed_at, dump_nodes, node_idx, dump_edges, edge_idx, gb->dump_vectors, gb->dump_vector_count, gb->dump_token_vecs, gb->dump_token_vec_count); + /* Read errno before anything else can touch it: the profiling macro + * below is already one library call away from losing the reason. */ + int finalize_errno = errno; CBM_PROF_END_N("dump", "6_write_db_finalize", t_finalize, node_idx + edge_idx); if (rc == 0) { rc = frc; } - log_dump_summary(node_idx, edge_idx); + if (rc != 0) { + log_dump_failed(rc, finalize_errno, node_idx, edge_idx); + } else { + log_dump_summary(node_idx, edge_idx); + } free_dump_resources(url_paths, local_names, edge_idx, dump_edges, dump_nodes, temp_to_final); cbm_free(CBM_MEM_CLASS_DUMP, src_nodes); return rc; diff --git a/tests/test_graph_buffer.c b/tests/test_graph_buffer.c index 256fc0ceca..8a32d5a341 100644 --- a/tests/test_graph_buffer.c +++ b/tests/test_graph_buffer.c @@ -9,6 +9,10 @@ #include "foundation/mem_core.h" #include #include "store/store.h" +#include "../src/foundation/compat.h" +#include "foundation/compat_fs.h" +#include "foundation/log.h" +#include #include /* ── Node operations ───────────────────────────────────────────── */ @@ -1120,6 +1124,72 @@ TEST(gbuf_flush_skips_orphan_edges) { PASS(); } +/* ── Publish failure reporting ───────────────────────────────── */ + +static char g_log_capture[4096]; +static CBMLogLevel g_prev_log_level; +static CBMLogFormat g_prev_log_format; + +static void capture_log_sink(const char *line) { + size_t used = strlen(g_log_capture); + size_t avail = sizeof(g_log_capture) - used; + if (avail <= 1) { + return; + } + int n = snprintf(g_log_capture + used, avail, "%s\n", line); + if (n < 0 || (size_t)n >= avail) { + g_log_capture[sizeof(g_log_capture) - 1] = '\0'; + } +} + +static void capture_logs_start(void) { + g_log_capture[0] = '\0'; + g_prev_log_level = cbm_log_get_level(); + g_prev_log_format = cbm_log_get_format(); + cbm_log_set_level(CBM_LOG_DEBUG); + /* The assertions below read the text encoding, so pin it rather than + * inherit whatever CBM_LOG_FORMAT left set. */ + cbm_log_set_format(CBM_LOG_FORMAT_TEXT); + cbm_log_set_sink(capture_log_sink); +} + +static const char *capture_logs_end(void) { + cbm_log_set_sink(NULL); + cbm_log_set_level(g_prev_log_level); + cbm_log_set_format(g_prev_log_format); + return g_log_capture; +} + +/* A dump that publishes nothing has to say so, and say why. Renaming onto an + * existing directory is how test_sqlite_writer already forces the publish to + * fail; here it stands in for any host that denies the rename (#1620). */ +TEST(gbuf_dump_failure_logs_reason) { + char dir[256]; + snprintf(dir, sizeof(dir), "/tmp/cbm_gbuf_pub_XXXXXX"); + ASSERT_NOT_NULL(cbm_mkdtemp(dir)); + + cbm_gbuf_t *gb = cbm_gbuf_new("test", "/tmp/repo"); + ASSERT_NOT_NULL(gb); + int64_t id = cbm_gbuf_upsert_node(gb, "Function", "main", "pkg.main", "main.go", 1, 10, "{}"); + ASSERT_GT(id, 0); + + capture_logs_start(); + int rc = cbm_gbuf_dump_to_sqlite(gb, dir); + const char *logs = capture_logs_end(); + + ASSERT(rc != 0); + ASSERT_NOT_NULL(strstr(logs, "gbuf.dump_failed")); + /* The reason survived the cleanup unlink. */ + ASSERT_NOT_NULL(strstr(logs, "errno=")); + ASSERT(strstr(logs, "errno=0 ") == NULL); + /* And the run is not also reported as a successful dump. */ + ASSERT(strstr(logs, "msg=gbuf.dump ") == NULL); + + cbm_gbuf_free(gb); + cbm_rmdir(dir); + PASS(); +} + /* ── Suite ─────────────────────────────────────────────────────── */ /* A worker buffer draws ids from the shared counter, so a dense id -> node @@ -1221,4 +1291,7 @@ SUITE(graph_buffer) { RUN_TEST(gbuf_shared_ids_null_fallback); RUN_TEST(gbuf_next_id_set_next_id_roundtrip); RUN_TEST(gbuf_next_id_null_safe); + + /* Publish failure reporting */ + RUN_TEST(gbuf_dump_failure_logs_reason); } diff --git a/tests/test_sqlite_writer.c b/tests/test_sqlite_writer.c index 1084d05299..a80fee0591 100644 --- a/tests/test_sqlite_writer.c +++ b/tests/test_sqlite_writer.c @@ -13,6 +13,7 @@ /* sqlite_writer.h is at internal/cbm/ — Makefile adds -Iinternal/cbm */ #include "sqlite_writer.h" /* CBMDumpNode, CBMDumpEdge, cbm_write_db */ #include "sqlite3.h" /* vendored/sqlite3/ via -Ivendored/sqlite3 */ +#include #include /* ── Helper: create temp file path ─────────────────────────────── */ @@ -101,6 +102,45 @@ static int count_temp_outputs_for(const char *path) { return count; } +/* Locate the writer's temp output for `path`. Same naming rule as + * count_temp_outputs_for, but returns the full path of the first match. */ +static int find_temp_output_for(const char *path, char *out, size_t out_size) { + char dir[256]; + char base[256]; + const char *slash = strrchr(path, '/'); + if (slash) { + size_t dir_len = (size_t)(slash - path); + if (dir_len == 0 || dir_len >= sizeof(dir)) { + return -1; + } + memcpy(dir, path, dir_len); + dir[dir_len] = '\0'; + snprintf(base, sizeof(base), "%s", slash + 1); + } else { + snprintf(dir, sizeof(dir), "."); + snprintf(base, sizeof(base), "%s", path); + } + + cbm_dir_t *d = cbm_opendir(dir); + if (!d) { + return -1; + } + size_t base_len = strlen(base); + int found = -1; + cbm_dirent_t *ent; + while ((ent = cbm_readdir(d)) != NULL) { + size_t name_len = strlen(ent->name); + if (name_len > base_len + 5 && strncmp(ent->name, base, base_len) == 0 && + strncmp(ent->name + base_len, ".tmp.", 5) == 0) { + snprintf(out, out_size, "%s/%s", dir, ent->name); + found = 0; + break; + } + } + cbm_closedir(d); + return found; +} + /* ── Tests ─────────────────────────────────────────────────────── */ TEST(sw_minimal_data) { @@ -877,6 +917,61 @@ TEST(sw_publish_preserves_live_reader) { /* ── Suite ─────────────────────────────────────────────────────── */ +TEST(sw_open_truncated_path_names_its_reason) { + /* final_path is a fixed 4K buffer and make_writer_temp_path only fails by + * truncation. Neither sets an errno of its own, so without naming one the + * caller reports whatever was left behind by an unrelated call. */ + char longpath[5000]; + memset(longpath, 'a', sizeof(longpath) - 1); + longpath[sizeof(longpath) - 1] = '\0'; + longpath[0] = '/'; + + errno = 0; + cbm_db_writer_t *w = cbm_writer_open(longpath); + ASSERT(w == NULL); + ASSERT_EQ(errno, ENAMETOOLONG); + PASS(); +} + +TEST(sw_publish_failure_reports_the_rename_not_the_cleanup) { +#ifdef _WIN32 + SKIP_PLATFORM("removing a still-open file to make the cleanup unlink fail"); +#endif + char dir[256]; + snprintf(dir, sizeof(dir), "/tmp/cbm_sw_cleanup_XXXXXX"); + ASSERT(cbm_mkdtemp(dir) != NULL); + + char final_path[320]; + snprintf(final_path, sizeof(final_path), "%s/db.sqlite", dir); + ASSERT_EQ(write_fixture_file(final_path, "destination"), 0); + + cbm_db_writer_t *w = cbm_writer_open(final_path); + ASSERT(w != NULL); + + /* Turn the still-open temp into a directory. The publish rename then fails + * with ENOTDIR (directory onto a file), and the cleanup unlink fails too + * (EISDIR on Linux, EPERM on macOS) — so only a saved errno still carries + * the rename's reason out to the caller. */ + char temp[512]; + ASSERT_EQ(find_temp_output_for(final_path, temp, sizeof(temp)), 0); + ASSERT_EQ(cbm_unlink(temp), 0); + ASSERT(cbm_mkdir_p(temp, 0700)); + + errno = 0; + int rc = cbm_writer_finalize(w, "test", "/tmp/test", "2026-07-07T00:00:00Z", NULL, 0, NULL, 0, + NULL, 0, NULL, 0); + int publish_errno = errno; + ASSERT(rc != 0); + ASSERT_EQ(publish_errno, ENOTDIR); + /* The destination is intact: a failed publish never replaces it. */ + ASSERT(fixture_file_equals(final_path, "destination")); + + cbm_rmdir(temp); + cbm_unlink(final_path); + cbm_rmdir(dir); + PASS(); +} + SUITE(sqlite_writer) { RUN_TEST(sw_minimal_data); RUN_TEST(sw_imports_local_name_unique); @@ -890,4 +985,6 @@ SUITE(sqlite_writer) { RUN_TEST(sw_publish_failure_preserves_destination_sidecars); RUN_TEST(sw_publish_supports_non_ascii_path); RUN_TEST(sw_publish_preserves_live_reader); + RUN_TEST(sw_open_truncated_path_names_its_reason); + RUN_TEST(sw_publish_failure_reports_the_rename_not_the_cleanup); }