feat(ci): show live sync progress in heartbeat - #168
Conversation
The node and db-sync sync loops already compute a live percentage. CI never showed it. PYTEST_ADDOPTS sets the log level to WARNING. This setting hides the progress log lines. Write the sync position to a small JSON file on each poll. The file sits next to node_sync.log and db_sync.log in the work directory. The heartbeat script reads it and prints percent, era, epoch, and slot on every tick. This works even if the log level changes again. Node and db-sync progress share one file, keyed by component. This matches the existing sync_markers status file pattern.
An independent review found a real defect. upsert_json_key raised on a missing, empty, or truncated existing file. Every call site was unguarded, inside the sync polling loops. In the db-sync loop, a raise here skipped the except block that uploads artifacts before giving up. A crash in this new observability code could lose a 30-hour run's artifacts. Fix, three parts: - upsert_json_key now treats an unreadable or invalid existing file as empty, instead of raising. - write_json_to_file now writes to a temp file, then renames it into place, so a reader or a crash mid-write never sees a truncated file. - Both progress-file call sites (node and db-sync) now catch OSError around the write and log a warning instead of raising. Progress display must never fail a sync test. Also fixes a docstring that named a function which does not exist (update_marker_status; the real name is _write_marker_to_status), and adds a final progress-file write right before each early return or break in the node sync loops, so progress reaches 100% instead of freezing at the last periodic tick.
|
Independent review found a real defect: upsert_json_key raised on a Fixed in bb49a84:
Also fixed: a docstring naming a function that does not exist, and a Verified locally against the exact failure cases (empty file, Second full review (node/db-sync path resolution, concurrency |
|
Correction to my last comment: the second full review (the broader |
|
Second review has now actually completed. It ran without worktree
Reproduced all three original failure scenarios from the review |
A second independent review found two more real gaps and one design issue in the sync-progress heartbeat work. heartbeat.sh dropped the whole progress line whenever sync_progress was null, even though era/epoch/slot were known and useful on their own. cardano-cli can omit syncProgress; the Python side already has a fallback for this case. The heartbeat now prints era/epoch/slot with "syncProgress unavailable" instead of nothing at all. jq's // operator only substitutes for null or false, not an empty string. node.py defaults a missing era to "", not null, so the "?" fallback for era never actually fired. Fixed by checking for an empty string explicitly. upsert_json_key duplicated an existing, unused helper, update_json_file, which already did the same read-merge-write. Since update_json_file had zero callers in the codebase, extended it with the same missing/corrupt-file tolerance and atomic write instead of keeping a second near-identical function, and pointed both progress call sites at it. Also adds a missing Args section to write_progress_file's docstring, to match its sibling wait_for_shelley_era.
e0d0836 to
d31a44c
Compare
|
Checked this PR against this workspace's AGENTS.md conventions Compliant: ruff/mypy/shellcheck clean, lazy %s logging (no f-strings Two real gaps found and fixed:
One gap intentionally left alone: node/init.py is missing |
|
db-sync combined pipeline run completed: success, 4h31m, preview, This also answers the earlier question about node and dbsync Not a bug. Node and db-sync are genuinely independent measurements Both node-only and combined pipelines are now verified live, on this |
Two ways the sync-progress plumbing could still abort a multi-hour run or publish a broken file: - `json.JSONDecodeError` did not cover `UnicodeDecodeError`, which a truncated or binary-garbage status file raises. It is a `ValueError`, not an `OSError`, so it escaped both this handler and the callers' `except OSError`. Catch `ValueError`. - The temp file had a fixed `.tmp` name, so two writers of the same path interleaved into it and `os.replace` then published the mangled result; a crash also left the temp file behind forever. Use `tempfile.mkstemp` and unlink on failure. Also flush+fsync before the rename, so a killed runner cannot leave a size-0 file behind, and chmod 0644 since mkstemp creates 0600.
The node and db-sync sides each hand-rolled the same progress write: timestamp formatting, `update_json_file`, and a warning on failure. Both guarded only `OSError`, so a serialization error (`TypeError` from `json.dump`) still killed a multi-hour sync over an observability write. Move it to `helpers.write_sync_progress(workdir, env, key, payload)`, which stamps `updated_at`, upserts one top-level key, and swallows any exception - the "never raises" promise the docstrings already made.
Was five `jq` forks per label, ten per heartbeat tick. Emit era, epoch, slot, updated_at and sync_progress as one TSV row instead; empty output means the label is absent or the file is unparsable, same as before.
Problem
The CI heartbeat gives no sync percentage. During a run, it shows only
a phase word, like "node syncing", and a raw log tail. Nobody can tell
how far a sync run is.
Root cause
The node and db-sync sync loops already compute a live percentage from
cardano-cli query tip. They log it, but the workflow setsPYTEST_ADDOPTS: --log-cli-level=WARNING. This setting hides the INFOlog line that carries the percentage. It never reaches the CI log.
Fix
Write the sync position to a small JSON file on each poll, next to
node_sync.loganddb_sync.log. This does not depend on pytest'slog level. The heartbeat script reads the file and prints the
percent, era, epoch, and slot on every tick.
Node and db-sync progress share one file, keyed by component. This
matches the existing
sync_markers_<env>.jsonstatus file pattern.Testing done
ruff check,ruff format --check, andmypypass clean.shellcheckpasses clean on the updated script.pytest --collect-onlystill collects all 103 tests.node-onlyandcombinedmode. Output looks correct in both.Testing still needed
This change touches core sync-loop code. It has not run against a
real syncing node yet. A live preview node-sync run on this branch is
in progress to confirm the real output.