Skip to content

perf(eagle3): gate the drafter quality diagnostics on the log level - #68

Merged
tpx818 merged 2 commits into
verl-project:mainfrom
khazic:khazic/perf/eagle3-drafter-quality-log-gating
Sep 1, 2026
Merged

perf(eagle3): gate the drafter quality diagnostics on the log level#68
tpx818 merged 2 commits into
verl-project:mainfrom
khazic:khazic/perf/eagle3-drafter-quality-log-gating

Conversation

@khazic

@khazic khazic commented Aug 24, 2026

Copy link
Copy Markdown
Contributor

Problem

Eagle3TrainerBackend.compute_loss collects per-step quality statistics unconditionally:

with torch.no_grad():
    if valid_position.any():                       # sync
        ...
        quality_step_stats.append({
            "step": idx,
            "tokens": int(step_tokens.detach().cpu().item()),          # sync
            "top1": round(float((...).detach().cpu().item()), 6),      # sync
            f"top{quality_topk}": round(float((...).detach().cpu().item()), 6),  # sync
        })
...
if quality_tokens.detach().float().item() > 0:     # sync
    logger.warning(                                # six more syncs in the args
        "[drafter logits quality] ...",
    )

Every one of those runs on every microbatch, and the numbers are log-only: nothing in the returned loss dict reads quality_top1_correct, quality_topk_correct, quality_tokens or quality_step_stats. The non-finite-position check and the sparse-restricted-CE summary have the same shape.

The summary line is also at WARNING, so a normal training run emits one warning per step reporting routine metrics.

The EAGLE-1/2 backend already guards the identical diagnostics:

# eagle1_trainer_backend.py
if logger.isEnabledFor(logging.DEBUG) and num_tokens.detach().item() > 0:

Fix

Compute diagnostics_enabled = logger.isEnabledFor(logging.DEBUG) once before the TTT loop and gate the quality block, the non-finite-position log and the sparse-restricted-CE log on it, then move the summary line from WARNING to DEBUG.

Behaviour at DEBUG is unchanged.

Validation

Ran a before/after repro on both main and this branch. It drives compute_loss with a stub draft at INFO and at DEBUG, counting Tensor.item() calls and recording what level the summary is emitted at.

Before/after repro output
=================== before: main (333b754) ===================
WARNING:[drafter logits quality] valid_tokens=7 top1_acc=0.142857 top5_acc=1.000000 local_ploss_sum=14.328695 local_tokens=7 per_step=[{'step': 0, 'tokens': 4, 'top1': 0.25, 'top5': 1.0}, {'step': 1, 'tokens': 3, 'top1': 0.0, 'top5': 1.0}]
WARNING:[drafter logits quality] valid_tokens=7 top1_acc=0.000000 top5_acc=1.000000 local_ploss_sum=12.494758 local_tokens=7 per_step=[{'step': 0, 'tokens': 4, 'top1': 0.0, 'top5': 1.0}, {'step': 1, 'tokens': 3, 'top1': 0.0, 'top5': 1.0}]
[one compute_loss call, ttt_length=2]
          at INFO : 12 Tensor.item() syncs, quality log = WARNING
          at DEBUG: 12 Tensor.item() syncs, quality log = WARNING

[verdict]
          diagnostics run at INFO too (12 syncs)
          summary line logs at WARNING
          RESULT: unconditional syncs on the hot path (bug present)

=================== after: this branch ===================
DEBUG:[drafter logits quality] valid_tokens=7 top1_acc=0.000000 top5_acc=1.000000 local_ploss_sum=12.494758 local_tokens=7 per_step=[{'step': 0, 'tokens': 4, 'top1': 0.0, 'top5': 1.0}, {'step': 1, 'tokens': 3, 'top1': 0.0, 'top5': 1.0}]
[one compute_loss call, ttt_length=2]
          at INFO : 0 Tensor.item() syncs, quality log = None
          at DEBUG: 12 Tensor.item() syncs, quality log = DEBUG

[verdict]
          diagnostics are skipped above DEBUG
          summary line logs at DEBUG
          RESULT: gated on the log level (fixed)

ttt_length=2 here; the per-step part of that count grows with ttt_length.

Tests

New file tests/integration/test_eagle3_diagnostics_gating_contract.py:

  • test_quality_diagnostics_are_silent_above_debug
  • test_quality_diagnostics_are_emitted_at_debug, which also pins the level at DEBUG
  • test_quality_diagnostics_do_not_sync_above_debug, which counts Tensor.item() calls

The tests attach a handler to the backend logger directly rather than using caplog.at_level, because that helper raises the logger to DEBUG and would mask the exact condition under test.

Full CPU suite (tests/integration tests/compat tests/config tests/examples) run on both sides:

Test suite before/after
### BASELINE (origin/main, 333b754) ###
FAILED tests/integration/test_drafter_runtime_control_contract.py::test_target_head_sync_defers_for_all_lm_head_drafters[DSPARK-veomni-npu-veomni_lm_head_full]
FAILED tests/integration/test_drafter_runtime_control_contract.py::test_target_head_sync_defers_for_all_lm_head_drafters[DFLASH-veomni-npu-veomni_lm_head_sparse]
FAILED tests/integration/test_drafter_runtime_control_contract.py::test_target_head_sync_defers_for_all_lm_head_drafters[EAGLE3-veomni-cuda-veomni_lm_head_full]
FAILED tests/integration/test_drafter_runtime_control_contract.py::test_target_head_sync_defers_for_all_lm_head_drafters[EAGLE1-fsdp-npu-engine_full_param]
FAILED tests/integration/test_drafter_runtime_control_contract.py::test_target_head_sync_defers_for_all_lm_head_drafters[DOMINO-fsdp2-cuda-engine_full_param]
FAILED tests/integration/test_drafter_runtime_control_contract.py::test_target_head_transfer_waits_after_actor_update
FAILED tests/integration/test_drafter_runtime_control_contract.py::test_async_publish_sets_pending_ref_and_waits_before_next_publish
FAILED tests/integration/test_dspark_trainer_backend.py::test_dspark_checkpoint_preserves_source_config_and_vllm_weight_names
FAILED tests/integration/test_verl_npu_vllm_compat.py::test_factory_fused_moe_survives_verl_npu_patch_import
9 failed, 245 passed, 2 warnings in 33.60s

### THIS BRANCH ###
(same 9 failures)
9 failed, 248 passed, 2 warnings in 21.11s

The same 9 tests fail on main and on this branch. They need optional dependencies (VeOmni, the NPU vLLM stack) that are absent in this environment, so they are pre-existing and unrelated. The +3 on this branch are the new tests above.

khazic added 2 commits August 24, 2026 19:45
compute_loss collected per-step quality stats unconditionally. Each step ran
valid_position.any() and three .item() calls to build quality_step_stats, then
the summary line fired at WARNING with six more .item() calls. Every one of them
is a device sync, they run on every microbatch, and the numbers are log-only:
nothing in the returned loss dict reads them.

The EAGLE-1/2 backend already guards the same diagnostics with
logger.isEnabledFor(logging.DEBUG). Do the same here, extend it to the
non-finite-position and sparse-restricted-CE logs, and move the summary line from
WARNING to DEBUG so routine per-step training metrics stop being reported as
warnings.

Behaviour at DEBUG is unchanged.

Signed-off-by: khazic <khazzz1c@gmail.com>
caplog.at_level raises the logger to DEBUG, which is the exact condition under
test, so the above-DEBUG case could never be observed through it.

Signed-off-by: khazic <khazzz1c@gmail.com>
@khazic

khazic commented Aug 25, 2026

Copy link
Copy Markdown
Contributor Author

The NPU vLLM dspark example failure here is runner port contention, not this change. The job died during engine init with:

torch.distributed.DistNetworkError: The server socket has failed to listen on any local network address. port: 38527, useIpv6: false, code: -98

code: -98 is EADDRINUSE. The same failure hit four PRs in this batch, on four different ports, and the job that failed does not line up with what each PR touches:

PR files changed failing job port
#66 peagle_trainer_backend.py, one error-message string in eagle3_trainer_backend.py eagle3 36693
#67 llama_eagle.py, modeling_peagle.py eagle3 35191
#68 eagle3_trainer_backend.py dspark 38527
#70 peagle_trainer_backend.py dflash 39403

#68 and #70 are the clearest: neither touches the dspark or the dflash code path, yet those are the jobs that failed.

Within a single run the three example jobs are serialized (on #63 they ran 11:25:05 to 11:42:21, 11:42:46 to 12:01:01, 12:01:27 to 12:19:55), so the contention comes from runs of different PRs overlapping. The failures cluster in the window where three PRs had example jobs in flight at once, and every job that started after that queue drained passed. The failed jobs also died in about 12 minutes against roughly 17 for a successful one, consistent with dying at engine init rather than during real work.

CPU unit tests and pre-commit pass on this PR.

Could a maintainer re-run the failed job? I do not have the permission to (gh run rerun returns Must have admin rights to Repository).

@tpx818
tpx818 merged commit 111bf2e into verl-project:main Sep 1, 2026
4 of 5 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants