# P4 probe: does --stop-after-steps really produce a resumable, Hub-verified segment boundary? # # Why this exists and what it buys with ~0.4 GPU-hours: `--stop-after-steps` is the mechanism every Phase 4 # session ends on, and Gate 3 never exercised it -- P3's legs used `--max-steps`, so each leg *was* a whole # run. The launcher's plan, the trainer's stop, HubPush's push-verify-pointer-prune order, the resume scan # that refuses a stale pointer, and the final-push-plus-terminal-pointer path are therefore untested # together. E-035/4 is precisely a defect in that untested seam, and the rehearsal kernel cannot reach it # because it needs two T4s. This does, against the published mix and the frozen 22L geometry, in one # session: leg 1 trains to a mid-run stop step, leg 2 wipes the disk, resumes from the Hub and runs to the # horizon. # # The probe writes to its own checkpoint repo, never to Cion-lab/ounce100m-ckpt: the first real session has # to find that repo absent, which is the RepoMissing branch E-034 was about. # # It carries a second question, the one the user pushed back on (D-017): gradient checkpointing costs 32 % # of the throughput (9,696 -> 12,792 tok/s, 29.7 h -> 22.5 h) and gives up the memory headroom, sitting at # 12.25 GB of ~14.56. So this cell runs the *real* geometry at --accum 32, micro 4, WITHOUT checkpointing, # for 180 steps, through three push/verify/prune cycles and one forced cold resume and the end-of-run # validation pass -- the three things a 30-step throughput cell cannot show: allocator drift across a few # hundred steps, the save path's host/GPU copies while the card is 84 % full, and the eval forward pass. # Peak memory is asserted, not eyeballed. If it holds, the run adopts it as D-018 with a finer push cadence # as the bounded blast radius; if it does not, D-017 stands and this is the measurement that says so. import hashlib, json, os, re, shutil, signal, subprocess, sys, threading, time os.chdir("/kaggle/working") sys.path.insert(0, "/kaggle/working") REV = "55b8fc47dd7799bf3fc08b7943421f578bac4a2c" WANT = { "ounce100m_credentials.py": ("ounce100m_credentials.py", "6525f62f03f2d73650a1eb4f70fcb52d1194caad4ca88b2d8bd8fd54f88339b6"), "shard_dataset.py": ("train/shard_dataset.py", "f35653bf4c8f2cfe7bb0c2c7835e308505fb5a84b4eb002d0f82f2cada768ca6"), "hubckpt.py": ("train/hubckpt.py", "d4b50ed0928c678c94ce6764612a4655f2959c0a7b91d6fd588e8efddff298b2"), "train_ounce100m.py": ("train/train_ounce100m.py", "dcb0ac199c0616575423ddea0d6b76d2257c06089d3f73aae0e0359de958ff03"), } BASE = "https://huggingface.co/Cion-lab/ounce100m-code/resolve/" + REV for p, (rp, want) in sorted(WANT.items()): assert subprocess.run(["curl", "-sfL", f"{BASE}/{rp}", "-o", p]).returncode == 0, ("fetch", rp) got = hashlib.sha256(open(p, "rb").read()).hexdigest() assert got == want, ("SHA MISMATCH", rp, got[:16], want[:16]) print("OK", p, got[:12], flush=True) import ounce100m_credentials as C print("creds:", json.dumps(C.install(verify=True)), flush=True) import hubckpt from huggingface_hub import HfApi MIX = "Cion-lab/ounce100m-mix-v1" # A scratch repo per attempt (dated), never the real run's repo: v1 left `final` at step 20 and v2 was # correctly refused by the stale-stop guard, so rather than clearing state between attempts each one gets an # empty repo. That also makes every attempt walk the RepoMissing resume branch (E-034) that session 1 hits. PROBE = os.environ.get("P4_PROBE_REPO") or ( "Cion-lab/ounce100m-ckpt-probe-" + time.strftime("%m%d-%H%M", time.gmtime())) ROOT, RUN = "/kaggle/working/mixroot", "/kaggle/working/run" # Two modes, one file, so the assertions are literally the same code in both. `smoke` is the user's # suggestion and it is the right order: 20 steps costs ~12 minutes and answers "does the training code run # at all, and does one checkpoint survive the push/verify/pointer/prune cycle" -- which is exactly what the # first run of this probe failed at, in 8.6 seconds, on a malformed torchrun command line (E-037). `soak` # is the 180-step memory question, and it is only worth 1.6 GPU-hours once the mechanics are known to work. MODE = os.environ.get("P4_PROBE_MODE", "soak") if MODE not in ("smoke", "soak"): # A typo here would otherwise run the 1.6-hour soak when a 13-minute smoke was asked for. raise SystemExit("P4_PROBE_MODE must be smoke or soak, got %r" % MODE) TLOG = "/kaggle/working/tlogs" # torchrun takes its first positional as the SCRIPT, not a command: passing sys.executable made # it compile the Python binary (E-037). --redirects is a per-rank bitmask into --log-dir (1=stderr, # 2=stdout, 3=both) and --tee repeats the same streams to this process, so the loss curve ยง5 requires # watching stays live *and* each rank's traceback is on disk for diag() below. TORCHRUN = ["torchrun", "--nproc_per_node=2", "--redirects", "3", "--tee", "3", "--log-dir", TLOG] TPS = 262144 # the run's real step shape, in tokens # `--tee` prefixes every forwarded line with the worker name, and this file parses those lines: v5's # harvest() found no `RUN_JSON ` because the trainer's rank-0 output arrived as # "[default0]: RUN_JSON {...}", so every step/token/param check reported false on a leg that had actually # passed, and the failure looked like a trainer bug rather than a probe bug. Strip it once, on the way in. TEE = re.compile(r"^\[(?:default|rank|worker)\d*\]:\s*") if MODE == "smoke": STEPS, PUSH_EVERY, STOP1, VAL = 20, 10, 10, 200000 T_LEG1, T_LEG2, T_FRESH = 1200, 900, 1500 else: STEPS, PUSH_EVERY, STOP1, VAL = 180, 60, 120, 2000000 # Sized from the model rather than guessed: 120 steps at ~20.5 s + build + three pushes + eval is # ~3,000 s, and 60 steps + cold pull + push + eval is ~1,700 s. The three ceilings must also fit under # the notebook's own session timeout (10,800 s for the soak) with room for the model build, because a # stage that outlives the container reports nothing at all (review point B5). T_LEG1, T_LEG2, T_FRESH = 3900, 2400, 1200 TOKENS = STEPS * TPS GATE_PEAK = (MODE != "smoke") # 20 steps says nothing about allocator drift T0 = time.time() def run(argv, label, timeout): print("=== " + label, flush=True) t0 = time.time() e = dict(os.environ); e["PYTHONPATH"] = "/kaggle/working" e["PYTHONUNBUFFERED"] = "1" # the -u that torchrun cannot carry e["NCCL_DEBUG"] = "WARN" # a rank that dies in a collective says so here and nowhere else e["TORCH_CPP_LOG_LEVEL"] = "WARNING" p = subprocess.Popen(argv, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True, env=e, bufsize=1, start_new_session=True) killed = [] def _kill(): killed.append(True) try: os.killpg(os.getpgid(p.pid), signal.SIGTERM) except Exception: p.kill() def _hard(): killed.append(True) try: os.killpg(os.getpgid(p.pid), signal.SIGKILL) except Exception: p.kill() timer = threading.Timer(timeout, _kill) timer.daemon = True timer.start() hard = threading.Timer(timeout + 90, _hard) hard.daemon = True hard.start() keep, lines = [], [] try: for line in p.stdout: line = TEE.sub("", line.rstrip("\n"), count=1) lines.append(line) if line.startswith(("CKPT ", "RUN_JSON ", "resume from", "auto-resume", "precision:", "params:", "mix:", "checkpoint hub target", "segment boundary", "validation skipped", "latest.json", "TRAIN DONE", "validation loss", "[rank ", "past the ", "peak_stats:", "Traceback", "Error")): print(" KEY>", line[:300], flush=True) keep.append(line) del keep[:-400] finally: timer.cancel() hard.cancel() rc = p.wait() if killed: print(" TIMEOUT after %d s" % timeout, flush=True) rc = -9 if rc != 0: # Probe v6 died on the early-stop leg and everything that could have said *where* was in `lines` # and never printed: the last-40-line tail was all torchrun's summary, and the failing rank's own # traceback came a hundred lines earlier. Grep the whole capture, then show the tail. pat = ("[rank", "Traceback", "Error", "error", "Exception", "assert", "exitcode", "Signal", "SystemExit", "refusing", "skipped", "CUDA", "NCCL", "out of memory", 'File "', "line ", "raise ", "FileNotFoundError", "RuntimeError") hits = [l for l in lines if any(q in l for q in pat)] print(" FAILURE LINES (%d of %d):" % (len(hits), len(lines)), flush=True) for l in hits[-45:]: print(" !", l[:300], flush=True) print(" TAIL:\n" + "\n".join(keep)[-2500:], flush=True) print("%s_RC %s seconds %.1f elapsed %.0f" % (label, rc, time.time() - t0, time.time() - T0), flush=True) return rc, "\n".join(lines) rc, out = run([sys.executable, "-c", "import sys; sys.path.insert(0, '/kaggle/working')\n" "from huggingface_hub import snapshot_download\n" "p = snapshot_download(repo_id='%s', repo_type='dataset',\n" " local_dir='/kaggle/working/mixroot', max_workers=4)\n" "print('mix at', p)\n" % MIX], "FETCH_MIX", T_FRESH) if rc != 0: raise SystemExit("VERDICT P4PROBE_STOP could not fetch the published mix") man = json.load(open(os.path.join(ROOT, "manifest.json"))) print("mix", man["n_shards"], "shards", format(int(man["total_tokens"]), ","), "tokens", "| probe repo", PROBE, flush=True) common = ["train_ounce100m.py", "--root", ROOT, "--out", RUN, "--hub-repo", PROBE, "--prune", "--seq-len", "1024", "--attn", "eager", # The flag under test. Passing both --grad-ckpt and --no-grad-ckpt would leave it to argparse's # last-wins ordering, which is not a thing to be ambiguous about in a probe of this recipe. "--no-grad-ckpt", "--micro-batch", "4", "--accum", "32", "--tokens", str(TOKENS), "--lr", "6e-4", "--push-every-steps", str(PUSH_EVERY), "--val-tokens", str(VAL), "--log-every", "5", "--resume", "auto"] def diag(tag): """torchrun's ChildFailedError said `error_file: ` and printed no traceback, which is useless for a rank-1-only failure. --redirects writes each rank's own stdout/stderr into the log dir, so print those on a failed leg: the exception is in there, and guessing at it costs a session.""" # v4's diag found no *.log at all, so list the tree as well as tailing it: if torchrun named the # files something else, this says so instead of printing nothing and leaving me guessing. rc, out = run(["bash", "-c", 'ls -R "%s" 2>&1 | head -40; ' 'for f in $(find "%s" -type f 2>/dev/null | head -8); do echo "==== $f"; ' 'tail -70 "$f"; done' % (TLOG, TLOG)], "DIAG_" + tag, 180) # run() only echoes lines it recognises, which made v4's and v6's diag print *nothing* while the # rank logs sat right there on disk. Say what was found, even if it is a traceback shape we do not # have a filter word for. print(" DIAG %s (%d chars, rc %s):\n%s" % (tag, len(out or ""), rc, (out or "")[-4000:]), flush=True) return out print("PROBE_REPO", PROBE, flush=True) shutil.rmtree(RUN, ignore_errors=True) rc1, o1 = run(TORCHRUN + common + ["--stop-after-steps", str(STOP1)], "LEG1_STOP_EARLY", T_LEG1) if rc1 != 0: diag("leg1") api = HfApi(token=os.environ["HF_TOKEN"]) try: listed = sorted(hubckpt.hub_listing(PROBE, "dataset", token=os.environ["HF_TOKEN"])) except Exception as e: listed = ["" % type(e).__name__] pushed = sorted({k.split("/")[1] for k in listed if k.startswith("ckpt/checkpoint-") and len(k.split("/")) > 1}) ptr = hubckpt.latest_pointer(PROBE, token=os.environ["HF_TOKEN"]) print("LEG1 pushed:", pushed, "pointer:", {k: ptr.get(k) for k in ("step", "path_in_repo", "error")}, flush=True) shutil.rmtree(RUN, ignore_errors=True) # force the cold-resume path (E-029's shape) rc2, o2 = run(TORCHRUN + common + ["--stop-after-steps", "0"], "LEG2_TO_HORIZON", T_LEG2) if rc2 != 0: diag("leg2") try: listed2 = sorted(hubckpt.hub_listing(PROBE, "dataset", token=os.environ["HF_TOKEN"])) except Exception as e: listed2 = ["" % type(e).__name__] ptr2 = hubckpt.latest_pointer(PROBE, token=os.environ["HF_TOKEN"]) def harvest(text, tag): for line in (text or "").splitlines(): if line.startswith(tag): try: return json.loads(line[len(tag):].strip()) except Exception: return {"unparsed": line[:200]} return {} rj1, rj2 = harvest(o1, "RUN_JSON "), harvest(o2, "RUN_JSON ") res = { "leg1_rc": rc1, "leg2_rc": rc2, "leg1": {"final_step": rj1.get("final_step"), "segment_stop": rj1.get("segment_stop"), "tokens_consumed": rj1.get("tokens_consumed"), "tok_per_s": rj1.get("tok_per_s"), "params": rj1.get("params"), "peak_gpu_gb": rj1.get("peak_gpu_gb"), "tok_per_s": rj1.get("tok_per_s"), "final_loss": rj1.get("final_loss"), "peak_alloc_gb": rj1.get("peak_gpu_gb"), "peak_alloc_gb_max_rank": rj1.get("peak_gpu_gb_max_rank"), "peak_reserved_gb_max_rank": rj1.get("peak_reserved_gb_max_rank"), "val_error": rj1.get("val_error"), "pushed": pushed, "pointer": {k: ptr.get(k) for k in ("step", "path_in_repo")}}, "leg2": {"final_step": rj2.get("final_step"), "segment_stop": rj2.get("segment_stop"), "tokens_consumed": rj2.get("tokens_consumed"), "val_ppl": rj2.get("val_ppl"), "peak_gpu_gb": rj2.get("peak_gpu_gb"), "peak_gpu_gb_max_rank": rj2.get("peak_gpu_gb_max_rank"), "peak_reserved_gb_max_rank": rj2.get("peak_reserved_gb_max_rank"), "val_error": rj2.get("val_error"), "tok_per_s": rj2.get("tok_per_s"), "final_loss": rj2.get("final_loss"), "pointer_after": {k: ptr2.get(k) for k in ("step", "path_in_repo")}, "has_final": any(k.startswith("final/") for k in listed2)}, "expect": {"steps_planned": STEPS, "push_every": PUSH_EVERY, "stop1": STOP1, "tokens_at_stop1": STOP1 * TPS, "tokens_at_horizon": STEPS * TPS, "grad_ckpt": False}, } res["checks"] = { "leg1_stopped_at_the_stop_step": rj1.get("final_step") == STOP1, "leg1_reported_a_segment": rj1.get("segment_stop") is True, # Integer compare: sorted() over names would order "checkpoint-120" before "checkpoint-60". "leg1_pushed_every_interval": sorted(int(x.split("-")[1]) for x in pushed) == list(range(PUSH_EVERY, STOP1 + 1, PUSH_EVERY)), "leg1_pointer_at_stop": ptr.get("step") == STOP1, "leg2_resumed_and_finished": rj2.get("final_step") == STEPS, "leg2_was_not_a_segment": rj2.get("segment_stop") is False, "leg2_pushed_final": any(k.startswith("final/") for k in listed2), "all_steps_present": sorted(int(x.split("-")[1]) for x in {k.split("/")[1] for k in listed2 if k.startswith("ckpt/checkpoint-")}) == list(range(PUSH_EVERY, STEPS + 1, PUSH_EVERY)), "leg2_pointer_terminal": ptr2.get("step") == STEPS and ptr2.get("path_in_repo") == "final", "tokens_match_the_arithmetic": rj1.get("tokens_consumed") == STOP1 * TPS and rj2.get("tokens_consumed") == STEPS * TPS, "params_are_the_frozen_model": rj1.get("params") == 106194240, "checkpointing_really_off": rj1.get("grad_ckpt") is False, # What gets gated is leg 1, because it is the only leg whose number means "training". `max_memory_reserved` # is the high-water mark since the process started, and leg 2 runs the validation pass before sampling # it, so leg 2's figure is training-plus-eval -- on smoke that came out 13.66 GB reserved against 12.7 # allocated, while the segment that never evaluated is the state the run sits in for 3,814 steps. Gating # on the eval-inflated number would fail D-018 for a state the run never occupies. The other rank's peak # and the reserved bytes are what an OOM is actually about, hence `max_rank` rather than rank 0 alone. "peak_memory_during_training_below_13_6_gb": (not GATE_PEAK) or ( (rj1.get("peak_reserved_gb_max_rank") or rj1.get("peak_gpu_gb_max_rank") or 99) <= 13.6), # Leg 1 skips validation by design (E-040's fix; the crash it was written for turned out to be E-044, # but the skip still stands -- a mid-run PPL point is not worth an untested path in a billed session), # and leg 2 must actually run it, because that is where the report's PPL comes from. "leg1_skipped_validation_by_design": rj1.get("val_skipped") is True and rj1.get("val_ppl") is None, "leg2_validation_actually_ran": (rj2.get("val_ppl") is not None and rj2.get("val_error") is None and rj2.get("val_skipped") is False), "no_nan_and_loss_moved": (rj1.get("final_loss") or 1e9) < 11.0 and (rj2.get("final_loss") or 1e9) < 11.0, } res["PROBE_PASSED"] = all(res["checks"].values()) and rc1 == 0 and rc2 == 0 print("PROBE_MODE", MODE, "steps", STEPS, "push_every", PUSH_EVERY, "stop1", STOP1, "peak_gate", GATE_PEAK, flush=True) print("PROBE_JSON_BEGIN") print(json.dumps(res, indent=1, default=str)) print("PROBE_JSON_END") print("VERDICT P4PROBE", "PASS" if res["PROBE_PASSED"] else "FAIL", [k for k, v in res["checks"].items() if not v], "seconds", round(time.time() - T0, 1), flush=True) raise SystemExit(0 if res["PROBE_PASSED"] else 5)