Split data-loader wait from preprocessing in schedule metrics

[jlamypoirier]

Claude Opus 4.8 authored this PR.

Problem

training.data_wait_time_ms (added in #564) reads near-zero (~19 ms) in the RL/streaming trainer while the DeepSpeed reference reports the true stream-block time (~4.2 s) — off by ~200×.

#564 timed next(context.data_iterator) inside _get_forward_input, but context.data_iterator is the _preprocess_data generator. So the metric clocked the raw loader block plus CPU preprocessing (share_batch_data / preprocess_batch, i.e. GPU transfer and batch prep). And in the RL path the loader is drained into a buffer before the schedule runs, so the generator's raw next() returns instantly and only preprocessing (~19 ms) is left to measure.

Fix

Move all timing into _preprocess_data, splitting it into two metrics:

• data_wait_time_ms — times only the raw next(data_iterator) pulls (time blocked on the data loader = input starvation).
• data_preprocessing_time_ms (new) — the generator's own active runtime (share_batch_data + preprocess_batch), with the clock paused across each yield so schedule compute between micro-batches is excluded.

Both are logged to the terminal (| data wait: … | data preprocessing: …). All timing is gated on context.metrics is not None, so there is no overhead off logging steps.

_get_forward_input no longer times anything. The data_batch_warn_time_ms warning and its config field are removed — the wait is now logged explicitly every step, so a threshold warning is redundant.

Notes

• No behavior change to training; metrics-only.
• No existing tests reference these metrics or the removed field. Verified: files compile, ScheduleConfig validates without the field, and the training log format's keys are all declared (no format-time KeyError).