[logging] Publish training metrics and step/epoch to Prometheus - #1931
[logging] Publish training metrics and step/epoch to Prometheus#1931eicherseiji wants to merge 21 commits into
Conversation
Adds skyrl/train/utils/phase_metrics.py with TrainingPhaseGauge, which sets a skyrl_training_phase gauge to 1.0 for the active macro-phase and 0.0 for the rest via ray.util.metrics. Ray exports it to the same Prometheus that scrapes node GPU metrics, so phase windows join GPU utilization on one wall-clock axis without correlating the experiment tracker by hand. The async loop sets the phase at each existing Timer boundary. Best-effort: the gauge silently no-ops when Ray metrics are unavailable, so it never breaks training or tests.
Generators produce rollout batches into a buffer and the trainer pulls mini_batch_size batches per step. The buffer depth tells which side is the bottleneck. Near zero means the trainer is starving for rollouts; near the cap means generation is paused at the staleness limit. It was previously visible only in a transient tqdm postfix. Log async/gen_buffer_qsize and async/gen_buffer_maxsize to the tracker each step, and publish the same values plus skyrl_mini_batch_size and skyrl_gen_group_keep_rate as Prometheus gauges via a new ScalarGauges helper (best-effort, no-ops without Ray, like TrainingPhaseGauge). keep_rate is kept / (kept + dropped) for the last mini-batch, the zero-variance drop rate under sample_full_batch, so a deep buffer of mostly droppable groups is distinguishable from a usable one.
- Emit only the two changed series per transition instead of sweeping all phases; the full sweep runs once at construction to seed every series for PromQL selectors. - Warn and keep the current phase on an unknown phase name instead of silently zeroing everything. - Rename phases to match their paired Timer keys so wandb timing/* keys and the Prometheus phase label share one vocabulary. - Construct the gauge in __init__ behind trainer.enable_training_phase_gauge, matching the RayGpuMonitor lifecycle. - Deduplicate docstrings and comments; add unknown-phase and disabled-by-flag tests.
Merges the updated seiji/training-phase-gauge base (gauge in __init__ behind a config flag, Timer-key phase names, two-write emit) and applies this PR's own review findings: - ScalarGauges takes a description at the first set() for a name instead of a constructor descriptions dict. - ScalarGauges construction and the loop-invariant skyrl_mini_batch_size set move to __init__; the step loop reads qsize/maxsize once into locals. - keep_rate uses mini_batch_size directly (the collect loop returns exactly that many kept groups here) and is also logged to the tracker as async/keep_rate, so both stores carry both drop signals. - Comment trims.
The gauge writes two in-process values per phase transition with no thread or I/O, so there is nothing an operator needs to switch off. Construct it unconditionally; it already no-ops without Ray.
Base dropped the enable_training_phase_gauge toggle; the gauge constructs unconditionally.
ScalarGauges had no functional dependency on TrainingPhaseGauge; the stack existed only because both classes shared phase_metrics.py. Move ScalarGauges to its own module (scalar_gauges.py, one module per concern) and revert the phase-gauge content from this branch's tree, so this PR is independently mergeable and its diff is buffer-only. Forward revert, no history rewrite; NovaSky-AI#1923 still owns the phase gauge.
The gauge description strings already say what each metric is; drop the comments restating them and the dashboard interpretation. Keep the one non-obvious invariant (collect returns exactly mini_batch_size kept groups) and the set() description semantics.
…#1930 Review feedback from SumanthRH. The buffer capacity is a run constant: compute it once in __init__ as the single source for both the queue construction and a one-time skyrl_gen_buffer_maxsize publish, kept for dashboard panels. Drop the per-step W&B keys: NovaSky-AI#1930 already logs async/gen_buffer_qsize_at_wait_start, and this PR keeps only the step-start Prometheus gauge for the depth.
Tracking.log now also publishes every numeric metric as a skyrl_-prefixed Prometheus gauge via ScalarGauges (foo/bar becomes skyrl_foo_bar). The timing/, async/, and generate/ families were stranded in the step-keyed experiment tracker, which does not join to wall-clock cluster metrics and does not survive a cluster restart. Non-numeric values and bools are skipped; the step number stays a value, never a label, so cardinality is bounded by the metric namespace.
skyrl_current_step, skyrl_epoch, and skyrl_step_{start,end}_unixtime,
set at step boundaries in the fully async loop. Prometheus series are
wall-clock keyed and the tracker is step keyed; these gauges are the
join key, so any cluster series can be attributed to a training step by
the window where the gauges held its number, without a tracker
round-trip.
Review feedback. The join key belongs to every training loop, not just
the fully async one; without it the sync loop's mirrored metrics would
have no step attribution. RayPPOTrainer now owns _loop_gauges and sets
skyrl_current_step, skyrl_epoch, and skyrl_step_{start,end}_unixtime at
its own step boundaries; in the base loop the start edge sits at logical
step start, so dynamic-sampling retries do not move it. The async
subclass inherits _loop_gauges and publishes its buffer constants after
super().__init__. Also reuse the step Timer's captured start time and
note the ordering invariant at the end-time write.
Review feedback. One-line comment without cross-branch references; docstring in two plain sentences.
Review feedback. This mirror runs at step commit, so mirroring trainer/global_step and trainer/epoch would add a series that lags a full step and conflicts with the step-start gauges published directly by the trainer. Skip both keys so step and epoch have one gauge each with the correct step-start timing.
The denylist existed only because the trainer published step and epoch twice: as trainer/* metrics (mirrored at commit, lagging a step) and as separate skyrl_current_step/skyrl_epoch gauges (set at step start). Give Tracking a log_gauge method sharing the mirror's registry, and have the trainer set skyrl_trainer_global_step / skyrl_trainer_epoch through it at step start. Those names match the mirror's output for trainer/global_step and trainer/epoch, so the start-timed set and the commit-time mirror are one gauge, not two. The mirror is now fully generic with no key skips. Also from the combined /simplify pass: - Extract _mark_step_start/_mark_step_end so both loops share the block. - Drop a stale mirror comment clause and a redundant test assertion.
There was a problem hiding this comment.
Code Review
This pull request introduces Prometheus-compatible scalar gauges to track training metrics in SkyRL. It adds a ScalarGauges utility that lazily creates Ray metrics gauges, integrates these gauges into the Tracking class to automatically publish numeric metrics, and adds step-start and step-end tracking to both synchronous and fully asynchronous trainers. The review feedback highlights two key improvements: first, using time.time() instead of step_timer.start_time in the asynchronous trainer to ensure correct Unix timestamps are published; second, replacing the numbers.Real check in the tracking class with a try-except float conversion to robustly support 0-dimensional PyTorch tensors.
| for _step_idx in range(self.global_step, (1 + epoch) * self.num_steps_per_epoch + 1): | ||
| with Timer("step", self.all_timings): | ||
| with Timer("step", self.all_timings) as step_timer: | ||
| self._mark_step_start(epoch, step_timer.start_time) |
There was a problem hiding this comment.
The _mark_step_start method expects a Unix timestamp (wall-clock time) because it publishes to skyrl_step_start_unixtime. However, Timer typically measures elapsed duration using monotonic clocks (such as time.monotonic() or time.perf_counter()), which do not represent Unix epoch time. Passing a monotonic timestamp will result in incorrect wall-clock metrics in Prometheus. To ensure correctness and consistency with the synchronous trainer, use time.time() directly.
| self._mark_step_start(epoch, step_timer.start_time) | |
| self._mark_step_start(epoch, time.time()) |
| for key, value in data.items(): | ||
| if isinstance(value, bool) or not isinstance(value, numbers.Real): | ||
| continue | ||
| self._prometheus.set(f"skyrl_{_PROMETHEUS_NAME_RE.sub('_', key)}", value) |
There was a problem hiding this comment.
Using isinstance(value, numbers.Real) to filter numeric values will silently exclude 0-dimensional PyTorch tensors (e.g., torch.tensor(1.5)), which do not inherit from numbers.Real. Since PyTorch tensors are extremely common in training/logging payloads, this will prevent many valid metrics from being published to Prometheus. Attempting to convert the value to float using a try-except block is much more robust and handles Python scalars, NumPy scalars, and 0-dimensional PyTorch tensors seamlessly, while safely ignoring strings, lists, and multi-element tensors.
for key, value in data.items():
if isinstance(value, bool):
continue
try:
val_float = float(value)
except (TypeError, ValueError):
continue
self._prometheus.set(f"skyrl_{_PROMETHEUS_NAME_RE.sub('_', key)}", val_float)Import ScalarGauges from metrics.py and drop the standalone scalar_gauges.py (now folded into metrics.py). Take main's buffer/keep-rate gauges in fully_async_trainer.py and keep only this PR's step/epoch marking hooks. Move the mirror's disable-on-failure guard into Tracking._publish_gauge, since metrics.py's ScalarGauges is intentionally unguarded.
What does this PR do?
Makes the training loop's metrics queryable in Prometheus alongside GPU and vLLM data, so loop state and GPU utilization join on one wall-clock axis in a single store.
New metrics:
skyrl_<metric>(Prometheus, every backend): every numeric value logged throughTracking.logis mirrored to a gauge of the same name, e.g.timing/run_trainingbecomesray_skyrl_timing_run_training. Strings and bools are skipped.skyrl_trainer_global_step,skyrl_trainer_epoch(Prometheus, per step): the step and zero-indexed epoch the loop is working on, so any metric can be sliced by step or epoch.skyrl_step_start_unixtime,skyrl_step_end_unixtime(Prometheus, per step): wall-clock step boundaries.The step gauges share the names
Tracking.logproduces fortrainer/global_stepandtrainer/epoch, so a step gauge and the metric published under that name are the same series.How
Trackingholds aScalarGauges(fromskyrl/train/utils/metrics.py) and mirrors every numericlogvalue to it.RayPPOTrainer._mark_step_start/_mark_step_endpublish the step gauges throughTracking.log_gauge, which writes to those same gauges, in both the sync and async loops. The async loop marks step start from the stepTimerso the gauge's timestamp matches the throughput window.Tests
tests/train/test_tracking.py(new): numeric metrics publish under sanitized names while strings and bools are skipped; a gauge set vialog_gaugeand the same-named published metric are one gauge object.End to end on a local Ray instance: the step gauges and a logged metric payload export from Ray's
/metricswith the expected names,trainer/global_stepmaps to a singleray_skyrl_trainer_global_stepseries, and the string and bool produce no gauge:ruff and black clean on changed files.