fix(espidf): ccache hash_dir=false so build variants share objects; log ninja/cmake timeouts

ESP-IDF compiles with -ggdb, and for debug builds ccache folds the cwd into
every cache key by default — CCACHE_BASEDIR does not exempt it (verified with
CCACHE_DEBUG on 4.11: 'Hashing CWD /var/lib/velxio-build/esp32s3/v_<hash>/
project/build'). Each build variant lives in its own dir, so every variant had
a private key space: eight esp32 variants of the SAME board each recompiled
all ~2100 IDF objects from scratch, the cache filled with dead per-directory
entries, and a cold Cardputer/S3 build (2263 steps) overran the 600s ninja
timeout on a busy box. CCACHE_NOHASHDIR=1 makes variants of the same
board/sdkconfig share objects; a cold variant becomes mostly cache hits. Only
DW_AT_comp_dir in .debug_info of a reused object can differ, which never
reaches the flashed .bin.

The timeout paths were silent server-side; they now log the build dir and how
many ninja steps completed, and the user-facing message says the partial
build is kept and a retry resumes.
This commit is contained in:
David Montero 2026-08-17 19:15:28 +02:00
parent 9118529d10
commit 7d63209d1e
3 changed files with 59 additions and 1 deletions

View File

@ -280,6 +280,17 @@ ENV IDF_CCACHE_ENABLE=1
# compiles even though some flags (-I, -fmacro-prefix-map) embed absolute
# paths into the command line.
ENV CCACHE_BASEDIR=/var/lib/velxio-build
# hash_dir=false. ESP-IDF compiles with -ggdb, and for debug builds ccache
# folds the cwd into every cache key by default; CCACHE_BASEDIR does NOT
# exempt it (verified with CCACHE_DEBUG on ccache 4.11: "Hashing CWD
# /var/lib/velxio-build/esp32s3/v_<hash>/project/build"). Since each build
# variant lives in its own dir, every variant had a private key space and a
# cold variant of an already-built board recompiled all ~2100 IDF objects
# from scratch — on a busy box that overran the 600s ninja timeout. With
# hash_dir off, variants of the same board/sdkconfig share objects. The
# only difference is DW_AT_comp_dir inside .debug_info of a reused object,
# which never reaches the flashed .bin.
ENV CCACHE_NOHASHDIR=1
# Cache cap + compression set as env vars (rather than via `ccache
# --set-config` at image-build time) because $CCACHE_DIR is a docker volume:
# anything written into /var/cache/ccache during the RUN step is masked at

View File

@ -195,6 +195,17 @@ def _evict_cold_variants(target_dir: Path, keep: int) -> None:
shutil.rmtree(d, ignore_errors=True)
def _ninja_log_step_count(build_dir: 'str | Path') -> int:
"""Number of completed build steps recorded in ``build_dir/.ninja_log``
(0 when absent/unreadable). Diagnostics only — used to say how far a
timed-out build got."""
try:
with open(Path(build_dir) / '.ninja_log', encoding='utf-8', errors='replace') as fh:
return max(0, sum(1 for _ in fh) - 1) # first line is the header
except OSError:
return 0
# ── .ino prototype generation ────────────────────────────────────────────────
# arduino-cli runs ctags over the sketch and injects forward declarations so
# the classic Arduino idiom — helpers defined AFTER setup()/loop() that use
@ -3587,6 +3598,10 @@ class ESPIDFCompiler:
try:
cmake_result = await asyncio.to_thread(_run_cmake)
except subprocess.TimeoutExpired:
logger.error(
f'[espidf] cmake configure timed out after {cmake_timeout}s '
f'in {build_dir}'
)
return {
'success': False,
'error': f'ESP-IDF cmake configure timed out ({cmake_timeout}s)',
@ -3626,9 +3641,24 @@ class ESPIDFCompiler:
try:
ninja_result = await asyncio.to_thread(_run_ninja)
except subprocess.TimeoutExpired:
# Silent before — a 600s failure left no server-side trace at all,
# so a slow-box incident (2026-08-17: cold S3 variant, ccache
# missing on every object) had to be reconstructed from the
# variant's .ninja_log. Say where it happened and how far it got.
done_steps = _ninja_log_step_count(build_dir)
logger.error(
f'[espidf] ninja build timed out after {NINJA_TIMEOUT_S}s in '
f'{build_dir} ({done_steps} steps logged)'
)
return {
'success': False,
'error': f'ESP-IDF build timed out ({NINJA_TIMEOUT_S}s)',
# ninja is incremental and the variant dir persists: the
# objects built so far are kept, so retrying picks up where
# this attempt stopped instead of starting over.
'error': (
f'ESP-IDF build timed out ({NINJA_TIMEOUT_S}s) — the partial '
f'build is kept; compile again to resume where it stopped'
),
'stdout': '',
'stderr': '',
}

View File

@ -446,3 +446,20 @@ def test_render_sdkconfig_idf5_per_target_drops(compiler: ESPIDFCompiler) -> Non
_TEMPLATE_DIR, idf_target='esp32s3', use_idf5=True,
)
assert 'CONFIG_ESPTOOLPY_FLASHFREQ_26M' not in s3_text # S3 has no 26M
def test_ninja_log_step_count(tmp_path) -> None:
"""Diagnostic helper for the ninja-timeout log line: counts completed
steps in .ninja_log (header excluded), 0 when the log is missing."""
from app.services.espidf_compiler import _ninja_log_step_count
build_dir = tmp_path / 'build'
assert _ninja_log_step_count(build_dir) == 0
build_dir.mkdir()
(build_dir / '.ninja_log').write_text(
'# ninja log v6\n'
'1\t20\t0\tesp-idf/a.obj\tdeadbeef\n'
'2\t30\t0\tesp-idf/b.obj\tcafebabe\n',
encoding='utf-8',
)
assert _ninja_log_step_count(build_dir) == 2