Skip to content

[ci] Surface worker process logs on perf hard regressions - #1701

Open
yogyam wants to merge 1 commit into
hao-ai-lab:mainfrom
yogyam:ci/1604-worker-logs-on-perf-regression
Open

[ci] Surface worker process logs on perf hard regressions#1701
yogyam wants to merge 1 commit into
hao-ai-lab:mainfrom
yogyam:ci/1604-worker-logs-on-perf-regression

Conversation

@yogyam

@yogyam yogyam commented Aug 8, 2026

Copy link
Copy Markdown
Contributor

Purpose

Fixes #1604.

When the performance CI fails on a hard regression, the only output is a one-liner like:

wan-t2v-1.3b-2gpu dit_time_s exceeded fixed threshold (current=18.252, threshold=10.000)

Inference runs in per-GPU worker subprocesses, and their logs — which explain why the run got slow (backend fallback, compilation miss, exception on a slow path, ...) — are never persisted or attributed to the failure. This PR captures worker logs per benchmark run and surfaces them on hard-regression failures.

Changes

  • New fastvideo/tests/performance/worker_log_capture.py (stdlib-only): WorkerLogCapture consumes the executor's worker log queue via a QueueListener into a size-capped RotatingFileHandler (10MB, backupCount=1, rollover keeps the recent tail) at results/worker_logs/worker_<benchmark_id>_<ts>.log; format_worker_log_tail() renders a delimited 200-line tail.
  • test_inference_performance.py: passes the queue to VideoGenerator.from_pretrained only (workers keep the handler for their lifetime → model load + warmups + measured runs all captured; passing it to generate_video would detach it after the first call). finally orders shutdown → drain → copy to $PERF_REPORTS_DIR/worker_logs/. Raw record gains a nullable worker_log_path field. Threshold assertions print the log tail before re-raising — covers PR runs, where a pytest failure means compare_baseline.py never executes.
  • compare_baseline.py: prints the same tail after the failure list for records that breached a fixed threshold — covers scheduled runs (PERF_UPLOAD_POLICY=always), the path producing the message quoted in the issue. Old/HF-synced records without the field degrade to an explicit "worker log unavailable" block. The field is deliberately not added to normalized/uploaded records.
  • .buildkite/scripts/lanes/performance.sh (the Slurm perf lane): one added cp -rf results/worker_logs "$PERF_REPORTS_DIR/" next to the existing JSON copy, so the full log lands in /workspace/artifacts/performance/ and is relayed by the CI host as a build artifact even when nothing prints. (An earlier revision of this PR put this in pr_test.sh; dropped after the Slurm migration marked that script dormant.)
  • Docs: docs/contributing/performance_benchmarks.md documents the field, the artifact, and the coverage caveat (only the fastvideo logger is forwarded — no torch/NCCL/raw stderr; ranks > 0 suppress logger.info by default, so capture = rank-0 INFO + all-rank WARNING/ERROR).

Test Plan

pytest fastvideo/tests/performance/test_worker_log_capture.py \
       fastvideo/tests/performance/test_compare_baseline_policy.py \
       fastvideo/tests/performance/test_inference_performance_result_schema.py
bash -n .buildkite/scripts/pr_test.sh
# End-to-end repro of the issue's exact scenario through the real compare_baseline.main()

Test Results

Test output
116 passed (7 new capture tests, 2 new compare-baseline cases incl. graceful degradation,
2 schema cases; zero regressions in existing tests)

Repro (dit_time_s=18.252 vs threshold 10.0) now produces:
Performance regression check failed:
  - wan-t2v-1.3b-2gpu dit_time_s exceeded fixed threshold (current=18.252, threshold=10.000)
==============================================================================
Worker log tail for wan-t2v-1.3b-2gpu (.../worker_wan-t2v-1.3b-2gpu.log)
==============================================================================
INFO Worker_DP0: DenoisingStage took 18.2s (expected ~9s)
WARNING Worker_DP1: attention backend fell back to TORCH_SDPA
==============================================================================

Developed on Apple Silicon (no CUDA): the real worker-log content and the Buildkite artifact upload need a GPU run — requesting /test performance. To watch the failure path fire end-to-end, temporarily lowering max_dit_time_s in .buildkite/performance-benchmarks/tests/wan-t2v-1.3b.json on a scratch branch reproduces it (the issue's own repro instruction).

Checklist

  • I ran pre-commit run --all-files and fixed all issues (fastvideo/tests/ is intentionally pre-commit-excluded; pr_test.sh and docs are covered and pass)
  • I added or updated tests for my changes (11 new/extended GPU-free tests)
  • I updated documentation if needed (docs/contributing/performance_benchmarks.md)
  • I considered GPU memory impact of my changes (none — log plumbing only)

🤖 Generated with Claude Code

@mergify mergify Bot added type: ci CI/CD infrastructure scope: infra CI, tests, Docker, build scope: docs Documentation labels Aug 8, 2026
@mergify

mergify Bot commented Aug 8, 2026

Copy link
Copy Markdown
Contributor

Merge Protections

🔴 1 of 1 protections blocking · waiting on 👀 reviews and 🤖 CI

Protection Waiting on
🔴 PR merge requirements 👀 reviews and 🤖 CI

🔴 PR merge requirements

Waiting for

  • #approved-reviews-by>=1
  • check-success=fastcheck-passed
  • check-success=full-suite-passed
This rule is failing.
  • #approved-reviews-by>=1
  • check-success=fastcheck-passed
  • check-success=full-suite-passed
  • check-success~=pre-commit
  • title~=(?i)^\[(feat|feature|bugfix|fix|refactor|perf|ci|doc|docs|misc|chore|kernel|new.?model|skill|skills|infra)\]

@yogyam
yogyam marked this pull request as ready for review August 8, 2026 03:08
@yogyam yogyam closed this Aug 8, 2026
@yogyam yogyam reopened this Aug 8, 2026
@mergify

mergify Bot commented Aug 9, 2026

Copy link
Copy Markdown
Contributor

This PR has merge conflicts with the base branch. Please rebase:

git fetch origin main
git rebase origin/main
# Resolve any conflicts, then:
git push --force-with-lease

@mergify mergify Bot added the needs-rebase PR has merge conflicts label Aug 9, 2026
@yogyam
yogyam force-pushed the ci/1604-worker-logs-on-perf-regression branch from 780bdae to c0fe954 Compare August 11, 2026 18:27
@mergify mergify Bot removed the needs-rebase PR has merge conflicts label Aug 11, 2026
@yogyam
yogyam force-pushed the ci/1604-worker-logs-on-perf-regression branch 2 times, most recently from 0dd3d55 to f247ad4 Compare August 26, 2026 19:24
@yogyam
yogyam force-pushed the ci/1604-worker-logs-on-perf-regression branch 4 times, most recently from e0054ad to 0eccbe7 Compare September 2, 2026 22:21
When the performance CI failed on a fixed-threshold breach, the only
output was a one-line message like "wan-t2v-1.3b-2gpu dit_time_s
exceeded fixed threshold (current=18.252, threshold=10.000)" - the
worker-process logs that explain why were never persisted or attached.

Capture worker logs per benchmark run via the existing executor
log_queue mechanism into a size-capped per-benchmark file, record its
path in the raw result (worker_log_path), print a 200-line tail on
hard-regression failures in both the pytest path (PR runs) and the
compare_baseline path (scheduled runs), and upload the log files as
Buildkite artifacts.

Fixes hao-ai-lab#1604

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@yogyam
yogyam force-pushed the ci/1604-worker-logs-on-perf-regression branch from 0eccbe7 to 9aa675e Compare September 5, 2026 04:08
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

scope: docs Documentation scope: infra CI, tests, Docker, build type: ci CI/CD infrastructure

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[ci] [Bug] Spit out the log from worker process

1 participant