test(compile): name each SQL test cache miss when a delta comparison fails

crates/sqlbuild-cache/src/artifacts/constants.rs

@@ -2,7 +2,8 @@
 pub const NEW_FILE_MODE: u32 = 0o666;
 /// The existing SQL-test cache snapshot format, shared by native readers and writers.
 pub(crate) const SQL_TEST_CACHE_VERSION: u64 = 5;
-pub(crate) const SQL_TEST_CACHE_FILE: &str = "sql-test-artifacts.json";
+/// The SQL-test cache snapshot's file name inside the compile cache directory.
+pub const SQL_TEST_CACHE_FILE: &str = "sql-test-artifacts.json";
 pub(crate) const MAX_SQL_TEST_CACHE_BYTES: u64 = 10_000_000;
 pub(crate) const MAX_SQL_TEST_CACHE_RECORDS: usize = 100_000;
 /// The extension every compiled SQL test artifact carries.

crates/sqlbuild-python/src/bindings/_helpers/compile_command/target_writer.rs

@@ -9,6 +9,7 @@ use pyo3::prelude::{
 };
 use pyo3::types::{PyDict, PyDictMethods, PyTuple, PyTupleMethods};
 use pyo3::{IntoPyObjectExt, pyclass, pyfunction, wrap_pyfunction};
+use sqlbuild_cache::artifacts::constants::SQL_TEST_CACHE_FILE;
 use sqlbuild_cache::artifacts::main::new_sql_test_record::new_sql_test_record;
 use sqlbuild_cache::artifacts::main::reusable_sql_test_record::reusable_sql_test_record;
 use sqlbuild_cache::artifacts::models::{SqlTestArtifactRecord, SqlTestRecordMiss};
@@ -66,6 +67,10 @@ const SQL_FILE_SUFFIX: &str = ".sql";
 const SQL_TEST_CACHE_LOGGER: &str = "sqlbuild.compile.reuse";
 /// The miss reason of a SQL test the cache file holds no record for.
 const NOT_RECORDED: &str = "not_recorded";
+/// Missed records a cache-miss debug line names before summarising the rest.
+const LOGGED_MISSES: usize = 16;
+/// Leading characters of a record key that name it in a cache-miss debug line.
+const LOGGED_KEY_CHARS: usize = 12;
 /// `functions/<language>` path components that already lead a function's path.
 const LANGUAGE_DIR_DEPTH: usize = 2;
 const PUBLISHED_STAGING_CHANGED: &str = "changed";
@@ -453,20 +458,43 @@ fn test_identities<'py>(
     Ok(identities)
 }
 
-/// Log why a warm SQL test artifact cache could not keep some artifacts, by reason.
-fn log_cache_misses(py: Python<'_>, misses: &BTreeMap<&'static str, usize>) -> PyResult<()> {
+/// Log a warm SQL test cache's misses: counts by reason, then each record's key and reason.
+fn log_cache_misses(
+    py: Python<'_>,
+    misses: &BTreeMap<&'static str, usize>,
+    missed: &[String],
+    unreadable: bool,
+) -> PyResult<()> {
     let reasons: String = misses
         .iter()
         .map(|(reason, count)| format!("{reason}={count}"))
         .collect::<Vec<_>>()
         .join(",");
+    let detail: String = if unreadable {
+        "the cache file held no usable records".to_owned()
+    } else {
+        let mut shown: Vec<String> = missed.iter().take(LOGGED_MISSES).cloned().collect();
+        if missed.len() > LOGGED_MISSES {
+            shown.push(format!("{} more", missed.len() - LOGGED_MISSES));
+        }
+        format!("records {}", shown.join(","))
+    };
     host::log_debug_message(
         py,
         SQL_TEST_CACHE_LOGGER,
-        &format!("SQL test artifact cache missed: {reasons}"),
+        &format!("SQL test artifact cache missed: {reasons} ({detail})"),
     )
 }
 
+/// Whether `cache_dir` holds a SQL test cache file, so an empty read means it was unreadable.
+fn cache_file_present(cache_dir: &Bound<'_, PyAny>) -> PyResult<bool> {
+    if cache_dir.is_none() {
+        return Ok(false);
+    }
+    let directory: PathBuf = cache_dir.extract()?;
+    Ok(directory.join(SQL_TEST_CACHE_FILE).is_file())
+}
+
 /// Plan every SQL test whose cached artifact under `target_dir` cannot be reused.
 pub(crate) fn plan_tests<'py>(
     target_dir: &Bound<'py, PyAny>,
@@ -503,6 +531,7 @@ pub(crate) fn plan_tests<'py>(
     let mut cached_paths: Vec<PathBuf> = Vec::new();
     let mut cached_records: Vec<(String, SqlTestArtifactRecord)> = Vec::new();
     let mut misses: BTreeMap<&'static str, usize> = BTreeMap::new();
+    let mut missed: Vec<String> = Vec::new();
     for (index, (test, identity)) in tests.into_iter().zip(identities).enumerate() {
         let Some((record_key, identity)) = identity else {
             pending.push((test.unbind(), None, None));
@@ -517,6 +546,8 @@ pub(crate) fn plan_tests<'py>(
             });
         if let Err(reason) = reusable {
             *misses.entry(reason).or_default() += 1;
+            let short: &str = record_key.get(..LOGGED_KEY_CHARS).unwrap_or(&record_key);
+            missed.push(format!("{short}:{reason}"));
         }
         if let Ok(record) = reusable {
             let path = tests_root_path.join(&record.relative_path);
@@ -528,8 +559,8 @@ pub(crate) fn plan_tests<'py>(
         }
         yield_interpreter(py, index);
     }
-    if !cached.is_empty() && !misses.is_empty() {
-        log_cache_misses(py, &misses)?;
+    if !misses.is_empty() && (!cached.is_empty() || cache_file_present(&cache_dir)?) {
+        log_cache_misses(py, &misses, &missed, cached.is_empty())?;
     }
     let pending_tests: Vec<Bound<'py, PyAny>> = pending
         .iter()

scripts/delta_compile_series/_helpers/outcomes.py

@@ -2,9 +2,11 @@
 
 from __future__ import annotations
 
+import json
 import re
 from itertools import zip_longest
 from pathlib import Path
+from typing import Any
 
 from scripts.delta_compile_series.constants import (
     AFTER_FAILED_RULES,
@@ -15,7 +17,11 @@
     DELTA_MISMATCH_PATTERN,
     DELTA_VERIFIED_LINE,
     DURATION_PATTERN,
+    LOG_DIAGNOSTICS_FILE,
+    LOG_RUNS_GLOB,
+    MAX_CACHE_LOG_LINES,
     MISMATCH_EXIT_CODE,
+    SQL_TEST_CACHE_LOG_PREFIX,
     STALE_PROBLEMS,
 )
 from scripts.delta_compile_series.models import DeltaCompileEdit, DeltaCompileOutcome
@@ -96,3 +102,31 @@ def full_compile_difference(
             )
             return f"{stream} differs from a full compile: {first[0]!r} vs {first[1]!r}"
     return None
+
+
+def log_runs(project: Path) -> frozenset[Path]:
+    """The per-invocation log directories a project holds."""
+
+    return frozenset(path for path in project.glob(LOG_RUNS_GLOB) if path.is_dir())
+
+
+def sql_test_cache_lines(*, project: Path, earlier: frozenset[Path]) -> str:
+    """Cache-miss reasons and record keys logged since `earlier`, never SQL text or environment."""
+
+    lines: list[str] = []
+    for run in sorted(log_runs(project) - earlier):
+        try:
+            text: str = (run / LOG_DIAGNOSTICS_FILE).read_text(encoding="utf-8", errors="replace")
+            rows: list[str] = text.splitlines()
+        except OSError:
+            continue
+        for row in rows:
+            try:
+                record: Any = json.loads(row)
+            except ValueError:
+                continue
+            message: Any = record.get("message") if isinstance(record, dict) else None
+            if isinstance(message, str) and message.startswith(SQL_TEST_CACHE_LOG_PREFIX):
+                lines.append(message)
+    shown: list[str] = lines[:MAX_CACHE_LOG_LINES]
+    return " | ".join(shown) if shown else "none logged"

scripts/delta_compile_series/constants.py

@@ -22,6 +22,10 @@
 PROJECT_CONFIG: str = "sqlbuild_project.toml"
 RANDOM_VALUE_LIMIT: int = 10**6
 FULL_COPY_SUFFIX: str = "_full_copy"
+LOG_RUNS_GLOB: str = "logs/*/*"
+LOG_DIAGNOSTICS_FILE: str = "diagnostics.jsonl"
+SQL_TEST_CACHE_LOG_PREFIX: str = "SQL test artifact cache"
+MAX_CACHE_LOG_LINES: int = 4
 DURATION_PATTERN: re.Pattern[str] = re.compile(r"\s*\(\d+(?:\.\d+)?s\)")
 COMPILE_TIMINGS_PATTERN: re.Pattern[str] = re.compile(r'\n  "compile_timings": \{[^{}]*\n  \}')
 MAX_FAILURES: int = 4

scripts/delta_compile_series/main/run_delta_compile_series.py

@@ -10,7 +10,12 @@
 
 from scripts.delta_compile_series._helpers.edits import edited_file
 from scripts.delta_compile_series._helpers.evidence import cache_state, keep_comparison_failure
-from scripts.delta_compile_series._helpers.outcomes import full_compile_difference, judged
+from scripts.delta_compile_series._helpers.outcomes import (
+    full_compile_difference,
+    judged,
+    log_runs,
+    sql_test_cache_lines,
+)
 from scripts.delta_compile_series.constants import (
     DELTA_COMPILE_LINE,
     DELTA_WEIGHT,
@@ -41,6 +46,7 @@ def _compared(
     copy: Path = project_dir.with_name(project_dir.name + FULL_COPY_SUFFIX)
     shutil.rmtree(copy, ignore_errors=True)
     _ = shutil.copytree(project_dir, copy, symlinks=True)
+    earlier: tuple[frozenset[Path], frozenset[Path]] = (log_runs(project_dir), log_runs(copy))
     before: dict[str, Any] = (
         {"delta": cache_state(project_dir), "full": cache_state(copy)} if diagnostics_dir else {}
     )
@@ -68,6 +74,12 @@ def _compared(
             )
         except OSError:
             pass
+    if problem is not None:
+        problem += (
+            f"; SQL test cache: delta "
+            f"{sql_test_cache_lines(project=project_dir, earlier=earlier[0])}"
+            f"; full {sql_test_cache_lines(project=copy, earlier=earlier[1])}"
+        )
     return outcome, problem
 
 

tests/e2e/src/sqlbuild/cli/commands/main/compile/helpers.py

@@ -5573,3 +5573,11 @@ def flip_compiled_sql_test_bytes(project_dir: Path) -> None:
 
     for artifact in sorted((project_dir / "target/compiled/tests").rglob("*.sql")):
         _ = artifact.write_text(artifact.read_text().replace("SELECT", "select", 1))
+
+
+def truncate_sql_test_cache(project_dir: Path) -> None:
+    """Cut every SQL test cache file to its first half, as a write cut short would leave it."""
+
+    for cache in sorted((project_dir / "target/cache").rglob("sql-test-artifacts.json")):
+        text: str = cache.read_text()
+        _ = cache.write_text(text[: len(text) // 2])

tests/e2e/src/sqlbuild/cli/commands/main/compile/test_sql_test_cache_misses.py

@@ -15,6 +15,7 @@
     append_to_compiled_sql_tests,
     flip_compiled_sql_test_bytes,
     run_installed_sqb,
+    truncate_sql_test_cache,
 )
 
 _MISS_LINE: str = "SQL test artifact cache missed"
@@ -34,6 +35,11 @@
             change=flip_compiled_sql_test_bytes,
             expected_debug_line=f"{_MISS_LINE}: content_changed=",
         ),
+        SqlTestCacheMissE2ETestCase(
+            description="a cut-short cache file logs that it held no usable records",
+            change=truncate_sql_test_cache,
+            expected_debug_line="(the cache file held no usable records)",
+        ),
     ],
     ids=lambda case: case.description,
 )

tests/unit/scripts/delta_compile_series/main/_test_types.py

@@ -13,3 +13,6 @@ class ComparisonEvidenceTestCase:
     steps: int = 1
     expected_mismatches: int = 1
     cache_relative_path: str = "orders/check.sql"
+    full_cache_log: str = (
+        "SQL test artifact cache missed: not_recorded=1 (the cache file held no usable records)"
+    )

tests/unit/scripts/delta_compile_series/main/helpers.py

@@ -52,6 +52,14 @@ def compile_project() -> DeltaCompileOutcome:
 
     def compile_full(copy: Path) -> DeltaCompileOutcome:
         _ = (copy / cache.relative_to(project)).write_text("{")
+        run: Path = copy / "logs/2026-11-10/full-run"
+        run.mkdir(parents=True)
+        _ = (run / "diagnostics.jsonl").write_text(
+            json.dumps({"message": "Delta compile fell back: disabled"})
+            + "\n"
+            + json.dumps({"message": test_case.full_cache_log})
+            + "\n"
+        )
         return DeltaCompileOutcome(
             0,
             test_case.stdout,

tests/unit/scripts/delta_compile_series/main/test_comparison_evidence.py

@@ -32,6 +32,9 @@ def test_given_mismatch_when_capturing_then_keeps_private_paired_evidence(
         "stderr differs from a full compile: '' vs 'SQL test planning  START'"
         in result.unexpected[0]
     )
+    assert result.unexpected[0].endswith(
+        f"; SQL test cache: delta none logged; full {test_case.full_cache_log}"
+    )
     directory: Path = destination / "failure-00"
     manifest: dict[str, Any] = json.loads((directory / "manifest.json").read_text())
     before: dict[str, Any] = json.loads((directory / "cache-before.json").read_text())