Skip to content

T2 · Engine event capture (golden fixtures)

Done 2026-10-28 · spike run on spike/engine-events · Snakemake 9.27.1 logger plugin: yes · Tower capture on Nextflow 26.10.4 and 25.10.9: yes · first nf-spectio (TraceObserverV2) built without Gradle and run next to nf-tower: same run in 6 of 6 runs · 15 fixtures · 24 differences with the specs, for TRIAGE3 · doc review approve 13/14

T2 figure: two lanes. Nextflow 26.10.4 and 25.10.9 run with -with-tower and -plugins nf-spectio; the nf-tower observer (create, begin, progress, complete) and nf-spectio (one POST per TraceObserverV2 hook) both post to a stdlib capture server, and report the same run name and session ID in 6 of 6 runs. Snakemake 9.27.1 runs with --logger spectio, which writes every LogRecord as one JSON line. The payloads are normalised (paths, host, user, token) into 12 Nextflow and 3 Snakemake fixtures. Three differences change a spec: the last onTaskComplete of a process arrives after its onProcessTerminate; Snakemake sends no attempt number and no exit code in job_error; a checkpoint grows the total from 32 to 67 through progress events, with no DAG event T2 figure: two lanes. Nextflow 26.10.4 and 25.10.9 run with -with-tower and -plugins nf-spectio; the nf-tower observer (create, begin, progress, complete) and nf-spectio (one POST per TraceObserverV2 hook) both post to a stdlib capture server, and report the same run name and session ID in 6 of 6 runs. Snakemake 9.27.1 runs with --logger spectio, which writes every LogRecord as one JSON line. The payloads are normalised (paths, host, user, token) into 12 Nextflow and 3 Snakemake fixtures. Three differences change a spec: the last onTaskComplete of a process arrives after its onProcessTerminate; Snakemake sends no attempt number and no exit code in job_error; a checkpoint grows the total from 32 to 67 through progress events, with no DAG event

Every number in the figure comes from the fixtures on spike/engine-events and the research note.

What changed

  • Spike code, throwaway, on branch spike/engine-events only (spikes/engine-events/):
    • snakemake/snakemake_logger_plugin_spectio/: a Snakemake logger plugin on snakemake-interface-logger-plugins 2.1.0 that writes every log record as JSON;
    • capture_server.py: a 48-line stdlib server that logs every request body;
    • nextflow/nf-spectio/: a first nf-spectio, one Groovy file, compiled with the Groovy compiler inside the Nextflow jar and installed as an unpacked plugin;
    • snakemake/runs.sh, nextflow/runs.sh, install.sh, normalise.py and three analyse_*.py summaries;
    • LOG.md: every command and its output.
  • Fixtures, spikes/engine-events/fixtures/: 15 JSON-lines files, 2.6 MB, named <engine>-<version>_<observer>_<run>.jsonl. The normalisation rules are in the note, Evidence.
  • Research note, new: Spike T2: engine event capture, with the table of differences.
  • Figure, new: tools/diagrams/t2_engine_events.py and its four outputs, registered in docs/assets/media.yaml.
  • Specs: none. Spikes report; the coordinator triages the 24 differences in TRIAGE3.

Why

Prompt: next-phase.md · T2. It asks for golden fixtures of what each engine sends, a first nf-spectio next to nf-tower (decision 0001 left their coexistence [to be validated]), and a check of two claims of checking-scenarios §11.1 and §11.5: event.handler.task.outputs in onTaskComplete, and "end of stage" as the last onProcessTerminate.

How to test it

On branch spike/engine-events, after the engines are installed (spikes/engine-events/install.sh, or dev/bootstrap.sh):

cd spikes/engine-events
bash snakemake/runs.sh "$(command -v snakemake)" "$PWD/.scratch"               # 3 Snakemake fixtures
bash nextflow/nf-spectio/build.sh "$(command -v nextflow)" ~/.nextflow/plugins   # install nf-spectio 0.0.1
PLUGIN=1 bash nextflow/runs.sh "$(command -v nextflow)" "$PWD/.scratch" 8765          # 6 fixtures, 26.10.4
PLUGIN=1 bash nextflow/runs.sh "$(command -v nextflow-25.10.9)" "$PWD/.scratch" 8766  # 6 fixtures, 25.10.9
python3 analyse_plugin.py fixtures/nextflow-26.10.4_plugin_flaky.jsonl fixtures/nextflow-26.10.4_tower_flaky.jsonl

The last command prints SAME RUN: True and lists the task events that arrived after their process's onProcessTerminate.

Evidence

Exit codes, the same on every engine version: flaky 0, toolerr 1, resume or rerun 0 (LOG.md §2, §5).

Same run, two observers (analyse_plugin.py, plugin fixture against the Tower fixture of the same run):

Version Run Run name Session ID Task IDs Tower / plugin
26.10.4 flaky intergalactic_montalcini d138a5c4-… 67 / 67
26.10.4 toolerr soggy_payne 38960569-… 65 / 65
26.10.4 resume irreverent_yalow 38960569-… 65 / 65
25.10.9 flaky pedantic_gauss ea241900-… 67 / 67
25.10.9 toolerr scruffy_hodgkin ac71c9a0-… 64 / 64
25.10.9 resume fervent_mendel ac71c9a0-… 65 / 65

onProcessTerminate before the last onTaskComplete, 26.10.4 flaky:

onProcessTerminate order: MAKE_READS, QC_STATS, SPLIT, QC_REPORT, ALIGN, MERGE, COMPARE, FINAL_REPORT
task events AFTER their process's onProcessTerminate: QC_STATS 1, ALIGN 1, MERGE 1, COMPARE 2 (all onTaskComplete)

Task outputs in onTaskComplete, SPLIT S04 (26.10.4): fileoutparam<0:1> → two chunk paths in the work directory; valueoutparam<0:0> (name sample) → S04.

Snakemake checkpoint and retry (snakemake-9.27.1_checkpoint_flaky_retry.jsonl): progress.total 32 → 67; job 103 is job_started, job_info, job_error, "Trying to restart job 103.", job_started, job_info, job_finished (fixture records seq 352–386), with no attempt number and no exit code in job_error.

Docs gate on this page's commit: see the step report.

Figures and media

  • t2-engine-events sketch, light and dark, at the top of this page: python3 tools/diagrams/t2_engine_events.py (PNG needs Playwright; rendered with uv run --with playwright==1.63.0).
  • t2-engine-events cast, below: python3 tools/media/cast.py tools/media/casts/t2-engine-events.yaml, run from branch spike/engine-events. The runs.sh step is replayed from the recorded output in LOG.md §5 (a stub, the engines are not run again); the two analyse_*.py commands run for real on the committed fixtures.
  • No screenshot: the step adds no screen.

Findings and open questions

Findings. 24 differences, each with its source and the spec section it touches, are in the note, Differences with the specs. The ones that change behaviour:

  1. End of stage on Nextflow (checking-scenarios §11.5): the last onTaskComplete of a process arrives after its onProcessTerminate, in every run, on both versions.
  2. Attempt state in nf-spectio: a failed attempt has handler.status COMPLETED; the failure is in the trace record and errorAction.
  3. Flow end: onFlowError arrives after onFlowComplete, and 25.10.9 sent onFlowComplete twice in a failed run.
  4. Snakemake exit codes are only in the text of the error record, never in job_error.
  5. nf-tower is downloaded from the plugin registry on first use, not shipped in the -dist jar: a constraint for offline clusters, and for nf-spectio too.

Open questions, for TRIAGE3:

  • Should nf-spectio send the task script and env (the Tower client does)?
  • Is end of stage "all processes terminated and all their tasks completed", or a short drain after the last onProcessTerminate?

Not done: a Gradle build and registry publication of nf-spectio, transport behaviour when the server is down, /heartbeat, Nextflow 25.04.8. They are follow-ups in the note.