Skip to content

osprey: Stage 7 report generation and pass-2 collection log nothing for up to 151 s at a time #4571

Description

@brendanx67

Measured on the 82-file SEA-AD Astral-DIA run of 2026-08-12 (8 h 38 m, exit 0). Run log D:\test\Pilot-MTG-Tissue-May2026\Astral-DIA\runs\seaad-82files-libdecoy-r1.0-protein-compact\run.log; analysed with ai/scripts/perfviz.py, which reports the gap distribution directly.

Reporting cadence across the whole run is good — median 2 s, p95 6 s — but there are five gaps of 30 s or more, totalling 523 s. One of them belongs to #4558 and is noted on that branch. This issue covers the other four, which are pre-existing.

gap at last line before the silence what runs during it
151 s 22:23:56 6096 protein groups pass 1.0% protein FDR Stage 7 report preparation, before the blib write. Managed memory is FLAT across the gap (37.7 -> 37.7 GB), so this is CPU-bound work, not GC
141 s 22:04:25 Released library fragments for 0 of 6324700 entries (749358 base_ids retained for the reported pool) pre-work before Collecting pass-2 survivors from 82 file(s).... The survivor collection itself already has a progress block; the silence is ahead of it
56 s 22:27:34 [ENTRAPMENT] Dropped 19279 unmatched entrapment peptides (...) finalizing the --model-diagnostics report
37 s 22:26:27 (blank) writing 51,597 library spectra to out.blib

Why this is worth fixing

Not throughput — 523 s is 1.7% of an 8 h 38 m run. It is observability. Someone watching a run cannot distinguish "working" from "hung" for two and a half minutes at a time, and on a run that costs the better part of a day that is the difference between catching a problem early and losing the day. It also makes an automated watchdog impossible to tune: any liveness threshold has to be set above 151 s, which is far too coarse to detect a real stall.

The fix is already idiomatic here

The codebase has the pattern — ProgressReporter with IO_INTERVAL_SECONDS, as used for Collecting pass-2 survivors from 82 file(s)... 100%. These four sites simply do not use it. The work is bounded and countable in every case (protein groups, files, spectra), so each is a progress block over a known total rather than a spinner.

Acceptance

perfviz.py on a subsequent 82-file run reports no gap >= 30 s. That is a measurable gate on a real run rather than a code review judgement, and perfviz.py already prints it as gaps >= 30s : N <-- OVER THRESHOLD.

Related: #4558 owns the fifth gap (138 s, experiment-level peak co-assignment in --model-diagnostics).

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    ospreyOsprey / OspreySharp DIA proteomics search tooltech-debtTechnical debt: cleanup, maintainability, dependency hygiene

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions