Skip to content

Commit aac4ed4

Browse files
committed
Implement MLPerf v6.1 RCP logging and deferred offline evaluation for DeepSWE
1 parent d4e62ab commit aac4ed4

13 files changed

Lines changed: 934 additions & 21 deletions

File tree

‎tests/examples/deepswe_mllog_utils_test.py‎

Lines changed: 154 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@
2222
import shutil
2323
import tempfile
2424
import types
25+
from typing import Any
2526
from unittest import mock
2627

2728
import numpy as np
@@ -30,6 +31,15 @@
3031
from tunix.utils import mllog_utils
3132

3233

34+
def _read_mllog_events(path: str) -> list[dict[str, Any]]:
35+
with open(path, "r", encoding="utf-8") as f:
36+
return [
37+
json.loads(line.split(":::MLLOG ", 1)[1])
38+
for line in f
39+
if ":::MLLOG " in line
40+
]
41+
42+
3343
@absltest.skipIf(mllog_utils.mllogger is None, "mlperf_logging is not installed")
3444
class MllogUtilsTest(absltest.TestCase):
3545

@@ -602,7 +612,150 @@ def test_train_stop(self):
602612
content = f.read()
603613

604614
self.assertIn('"key": "block_stop"', content)
605-
self.assertIn('"key": "run_stop"', content)
615+
# run_stop is emitted by the offline evaluator, not by train_stop.
616+
self.assertNotIn('"key": "run_stop"', content)
617+
618+
def test_compute_val_start_step(self):
619+
self.assertEqual(mllog_utils.compute_val_start_step(256), 18)
620+
self.assertEqual(mllog_utils.compute_val_start_step(512), 10)
621+
self.assertEqual(mllog_utils.compute_val_start_step(1024), 7)
622+
self.assertEqual(mllog_utils.compute_val_start_step(256, 1), 1)
623+
self.assertEqual(mllog_utils.compute_val_start_step(256, 0), 18)
624+
with self.assertRaises(ValueError):
625+
mllog_utils.compute_val_start_step(0)
626+
627+
def test_append_checkpoint_manifest_upserts_sorted_records(self):
628+
manifest_path = os.path.join(
629+
self.test_dir, "mllog", "eval_checkpoints.jsonl"
630+
)
631+
for step, ts_ms in ((19, 2000), (18, 1000), (18, 1500)):
632+
mllog_utils.append_checkpoint_manifest(
633+
manifest_path,
634+
{
635+
"step": step,
636+
"checkpoint_path": f"gs://ckpt/{step}/model_params",
637+
"timestamp_ms": ts_ms,
638+
"samples_count": step * 256,
639+
"val_start_at": 18,
640+
},
641+
)
642+
with open(manifest_path, "r", encoding="utf-8") as f:
643+
records = [json.loads(line) for line in f]
644+
self.assertEqual([r["step"] for r in records], [18, 19])
645+
self.assertEqual([r["timestamp_ms"] for r in records], [1500, 2000])
646+
647+
def test_configure_logger_downloads_existing_gcs_log_before_config(self):
648+
calls = mock.MagicMock()
649+
fake_mllogger = mock.MagicMock()
650+
fake_mllogger.logger.handlers = []
651+
with (
652+
mock.patch.object(mllog_utils, "mllog", calls.mllog),
653+
mock.patch.object(mllog_utils, "mllogger", fake_mllogger),
654+
mock.patch.object(mllog_utils, "_is_master_process", return_value=True),
655+
mock.patch.object(mllog_utils, "_gcs_target_path", None),
656+
mock.patch.object(mllog_utils, "_local_log_path", None),
657+
mock.patch.object(
658+
mllog_utils, "_download_from_gcs_if_exists", calls.download
659+
),
660+
):
661+
mllog_utils.configure_logger(metric_logger_dir="gs://b/mllog", seed=42)
662+
local_path = mllog_utils._local_log_path # pylint: disable=protected-access
663+
664+
self.assertEqual(
665+
[c[0] for c in calls.mock_calls], ["download", "mllog.config"]
666+
)
667+
calls.download.assert_called_once_with("gs://b/mllog/seed_42.out", local_path)
668+
self.assertEqual(
669+
os.path.abspath(calls.mllog.config.call_args.kwargs["filename"]),
670+
local_path,
671+
)
672+
673+
def test_offline_eval_rcp_sequence_converged(self):
674+
log_dir = self.test_dir
675+
args = types.SimpleNamespace(batch_size=16, num_generations=16)
676+
mllog_utils.configure_logger(metric_logger_dir=log_dir, seed=42)
677+
mllog_utils.train_stop(args, step=19, time_ms=2000)
678+
self.assertFalse(
679+
mllog_utils.log_offline_eval_step(
680+
step=18,
681+
samples_count=4608,
682+
eval_accuracy=0.65,
683+
checkpoint_timestamp_ms=1000,
684+
)
685+
)
686+
self.assertTrue(
687+
mllog_utils.log_offline_eval_step(
688+
step=19,
689+
samples_count=4864,
690+
eval_accuracy=0.70,
691+
checkpoint_timestamp_ms=2000,
692+
is_last_checkpoint=True,
693+
)
694+
)
695+
696+
events = _read_mllog_events(os.path.join(log_dir, "seed_42.out"))
697+
self.assertEqual(
698+
[e["key"] for e in events],
699+
["block_stop"] + ["eval_start", "eval_accuracy", "eval_stop"] * 2
700+
+ ["run_stop"],
701+
)
702+
self.assertEqual(events[0]["time_ms"], 2000)
703+
self.assertEqual(events[0]["metadata"]["step"], 19)
704+
self.assertEqual([events[2]["value"], events[5]["value"]], [0.65, 0.70])
705+
run_stop = events[-1]
706+
self.assertEqual(run_stop["time_ms"], 2000)
707+
self.assertEqual(run_stop["metadata"]["status"], "success")
708+
self.assertEqual(run_stop["metadata"]["samples_count"], 4864)
709+
710+
def test_offline_eval_rcp_sequence_not_converged(self):
711+
log_dir = self.test_dir
712+
mllog_utils.configure_logger(metric_logger_dir=log_dir, seed=42)
713+
for step, ts_ms in ((18, 1000), (19, 2000), (20, 3000)):
714+
self.assertFalse(
715+
mllog_utils.log_offline_eval_step(
716+
step=step,
717+
samples_count=step * 256,
718+
eval_accuracy=0.5,
719+
checkpoint_timestamp_ms=ts_ms,
720+
is_last_checkpoint=step == 20,
721+
)
722+
)
723+
724+
events = _read_mllog_events(os.path.join(log_dir, "seed_42.out"))
725+
run_stops = [e for e in events if e["key"] == "run_stop"]
726+
self.assertLen(run_stops, 1)
727+
self.assertEqual(events[-1]["key"], "run_stop")
728+
self.assertEqual(run_stops[0]["time_ms"], 3000)
729+
self.assertEqual(run_stops[0]["metadata"]["status"], "aborted")
730+
self.assertEqual(run_stops[0]["metadata"]["samples_count"], 5120)
731+
732+
def test_mlperf_6_1_0_init_print_disclosures(self):
733+
fake_mllogger = mock.MagicMock()
734+
with (
735+
mock.patch.object(mllog_utils, "mllogger", fake_mllogger),
736+
mock.patch.object(mllog_utils, "_is_master_process", return_value=True),
737+
mock.patch.object(mllog_utils, "_flush_to_gcs_if_needed"),
738+
):
739+
args = types.SimpleNamespace(
740+
batch_size=16,
741+
num_generations=16,
742+
max_prompt_length=4096,
743+
max_response_length=61440,
744+
)
745+
mllog_utils.init_print(args)
746+
emitted = {
747+
c.kwargs["key"]: c.kwargs["value"]
748+
for c in fake_mllogger.event.call_args_list
749+
}
750+
self.assertEqual(emitted["eval_samples"], 251)
751+
self.assertEqual(emitted["max_sequence_length"], 65536)
752+
for key in (
753+
"lowest_numerical_precision_in_linear",
754+
"lowest_numerical_precision_in_attn",
755+
"lowest_numerical_precision_in_comm",
756+
):
757+
self.assertEqual(emitted[key], "bfloat16")
758+
self.assertEqual(emitted["config_filename"], "qwen35_397b_grpo")
606759

607760

608761
if __name__ == "__main__":

‎tests/experimental/examples/deepswe_dist/eval_deepswe_test.py‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -168,6 +168,21 @@ def test_missing_and_failed_attempts_are_not_dropped(self):
168168
with self.assertRaisesRegex(ValueError, "duplicate"):
169169
eval_lib.summarize(rows + [rows[0]], ["a", "b"], 4)
170170

171+
def test_pass_at_4_is_reported_with_more_attempts(self):
172+
rows = [
173+
dict(
174+
instance_id="a",
175+
attempt=i,
176+
reward=float(i == 5),
177+
resolved=i == 5,
178+
status="SUCCEEDED",
179+
)
180+
for i in range(8)
181+
]
182+
summary = eval_lib.summarize(rows, ["a"], 8)
183+
# Unbiased pass@k = 1 - C(n - c, k) / C(n, k) with n=8, c=1.
184+
self.assertEqual(summary["pass_at_k"], {"1": 1 / 8, "4": 1 / 2, "8": 1.0})
185+
171186
def test_reward_comes_from_trajectory_not_completion_status(self):
172187
response = types.SimpleNamespace(
173188
error=None,

‎tunix/experimental/examples/deepswe_dist/eval_deepswe.py‎

Lines changed: 116 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -128,6 +128,59 @@ def parse_args(argv=None):
128128
)
129129
p.add_argument("--max_warmpool_size", type=int, default=1)
130130
p.add_argument("--output_dir", default="eval_results")
131+
p.add_argument(
132+
"--rcp_logging",
133+
type=boolean,
134+
nargs="?",
135+
const=True,
136+
default=os.environ.get("RCP_LOGGING", "0").lower() in ("1", "true"),
137+
help="Enable MLPerf RCP (mllog) compliance logging.",
138+
)
139+
p.add_argument(
140+
"--metric_logger_dir",
141+
default=os.environ.get("METRIC_LOGGER_DIR", ""),
142+
help="Directory or GCS URI for MLPerf RCP output (seed_<seed>.out).",
143+
)
144+
p.add_argument(
145+
"--target_accuracy",
146+
type=float,
147+
default=float(os.environ.get("TARGET_ACCURACY", "0.69")),
148+
help="Target evaluation accuracy for MLPerf RCP compliance logging.",
149+
)
150+
p.add_argument(
151+
"--checkpoint_step",
152+
type=int,
153+
default=int(os.environ.get("CHECKPOINT_STEP", "0")),
154+
help="Optimizer step corresponding to the evaluated checkpoint.",
155+
)
156+
p.add_argument(
157+
"--checkpoint_timestamp_ms",
158+
type=int,
159+
default=(
160+
int(os.environ["CHECKPOINT_TIMESTAMP_MS"])
161+
if os.environ.get("CHECKPOINT_TIMESTAMP_MS", "").strip()
162+
else None
163+
),
164+
help=(
165+
"Training epoch timestamp (ms) when the checkpoint weights were "
166+
"updated, used to backdate run_stop."
167+
),
168+
)
169+
p.add_argument(
170+
"--samples_count",
171+
type=int,
172+
default=int(os.environ.get("SAMPLES_COUNT", "0")),
173+
help="Cumulative training samples at checkpoint_step.",
174+
)
175+
p.add_argument(
176+
"--is_last_checkpoint",
177+
type=boolean,
178+
nargs="?",
179+
const=True,
180+
default=os.environ.get("IS_LAST_CHECKPOINT", "0").lower()
181+
in ("1", "true"),
182+
help="Whether this checkpoint is the final checkpoint in the manifest.",
183+
)
131184
a = p.parse_args(argv)
132185
for name in (
133186
"mesh_fsdp",
@@ -268,7 +321,10 @@ def summarize(rows, instance_ids, attempts):
268321
total = len(instance_ids) * attempts
269322
solved = sum(row["resolved"] for row in rows)
270323
pass_at_k = {}
271-
for k in sorted({1, attempts}):
324+
ks = {1, attempts}
325+
if attempts >= 4:
326+
ks.add(4)
327+
for k in sorted(ks):
272328
values = []
273329
for group in grouped.values():
274330
c = sum(row["resolved"] for row in group)
@@ -423,6 +479,13 @@ def load_entries(a):
423479

424480
async def run_controller(a):
425481
from tunix.experimental.worker import remote_execution
482+
from tunix.utils import mllog_utils
483+
484+
if getattr(a, "rcp_logging", False) and getattr(a, "metric_logger_dir", ""):
485+
mllog_utils.configure_logger(
486+
metric_logger_dir=a.metric_logger_dir,
487+
seed=getattr(a, "seed", 42),
488+
)
426489

427490
entries = load_entries(a)
428491
run_id = (
@@ -458,6 +521,8 @@ async def run_controller(a):
458521
failure = None
459522
fleet = None
460523
entry_stream = entries
524+
t_eval_start = None
525+
eval_start_time_ms = None
461526

462527
def record(row):
463528
writer.record(row)
@@ -479,6 +544,8 @@ async def ready(handle):
479544
raise ValueError(f"Worker/controller model settings differ: {profile}")
480545

481546
await asyncio.gather(*(ready(h) for h in handles))
547+
t_eval_start = time.monotonic()
548+
eval_start_time_ms = time.time_ns() // 1_000_000
482549
if a.use_agent_sandbox:
483550
from examples.deepswe import sandbox_utils # pylint: disable=import-outside-toplevel
484551

@@ -535,12 +602,60 @@ async def ready(handle):
535602
from examples.deepswe import sandbox_utils # pylint: disable=import-outside-toplevel
536603

537604
await asyncio.to_thread(sandbox_utils.teardown_global_fleet)
605+
validation_time = (
606+
time.monotonic() - t_eval_start if t_eval_start is not None else None
607+
)
538608
summary = summarize(
539609
all_rows,
540610
[str(e["instance_id"]) for e in entries],
541611
a.num_rollouts_per_instance,
542612
)
543613
summary["fatal_error"] = failure
614+
expected_attempts = int(summary.get("expected_attempts") or 0)
615+
error_attempts = int(summary.get("error_attempts") or 0)
616+
eval_ok = (
617+
failure is None
618+
and bool(summary.get("complete"))
619+
and (expected_attempts > 0 and error_attempts < expected_attempts)
620+
)
621+
pass_at_k = summary.get("pass_at_k") or {}
622+
eval_accuracy = float(
623+
pass_at_k.get(
624+
"4",
625+
pass_at_k.get(
626+
str(getattr(a, "num_rollouts_per_instance", 4)),
627+
summary.get("mean_reward", 0.0),
628+
),
629+
)
630+
)
631+
target_acc = float(getattr(a, "target_accuracy", 0.69))
632+
target_reached = bool(eval_ok and eval_accuracy >= target_acc)
633+
rcp_logged = False
634+
if getattr(a, "rcp_logging", False) and eval_ok:
635+
mllog_utils.start_eval(
636+
step=int(getattr(a, "checkpoint_step", 0)),
637+
samples_count=int(getattr(a, "samples_count", 0)),
638+
time_ms=eval_start_time_ms,
639+
)
640+
target_reached = mllog_utils.log_offline_eval_step(
641+
step=int(getattr(a, "checkpoint_step", 0)),
642+
samples_count=int(getattr(a, "samples_count", 0)),
643+
eval_accuracy=eval_accuracy,
644+
target_accuracy=target_acc,
645+
checkpoint_timestamp_ms=getattr(a, "checkpoint_timestamp_ms", None),
646+
is_last_checkpoint=bool(getattr(a, "is_last_checkpoint", False)),
647+
validation_time=validation_time,
648+
emit_start_eval=False,
649+
)
650+
rcp_logged = True
651+
summary["rcp_logged"] = rcp_logged
652+
summary["target_accuracy"] = target_acc
653+
summary["target_reached"] = bool(target_reached)
654+
summary["checkpoint_step"] = int(getattr(a, "checkpoint_step", 0))
655+
summary["checkpoint_timestamp_ms"] = getattr(
656+
a, "checkpoint_timestamp_ms", None
657+
)
658+
summary["samples_count"] = int(getattr(a, "samples_count", 0))
544659
try:
545660
writer.write("summary.json", summary)
546661
finally:

0 commit comments

Comments
 (0)