Repository navigation
[VideoGenX] measure requests and validate generated media / [VideoGenX] 测量请求并校验生成媒体 - #4658
edwingao28 wants to merge 22 commits into
Conversation
830f229 to
f45993b
Compare
f45993b to
c7570bd
Compare
c7570bd to
3097220
Compare
b997639 to
f728cc5
Compare
f728cc5 to
b6961d6
Compare
b6961d6 to
c659df9
Compare
c659df9 to
d9353c8
Compare
|
Claude finished @edwingao28's task in 2m 46s —— View job PR #4658 review
Summary: One 🟡 warning (inline on |
| for record in run["records"]: | ||
| expected = derive(events, record.get("job_id"), evidence["instance_id"]) | ||
| if record.get("server_timings") != expected: | ||
| raise ValueError("server timings differ from request-correlated raw events") |
There was a problem hiding this comment.
🟡 WARNING: Bundles with a timed-out request can never be verified.
Why it matters: runner.attempt calls collect(job_id) in its finally block right after the client gives up. For a timeout (or transport_error/interrupted after job_submitted), the server keeps running. It writes scheduler_dispatch / forward_finished / media_ready to the ledger later, so the snapshot in record["server_timings"] is partial (or None). This loop then re-derives the record from the final ledger, gets a different result and raises "server timings differ from request-correlated raw events". The run itself is fine, but the whole bundle gets rejected. That is the "server completion may be unknown" case the runner is built to keep. Successful and provider_failed records are unaffected, because the server writes all their events before the client sees a terminal status.
Fix: Only require exact equality where the snapshot is known to be final. For other records, require the stored snapshot to be a prefix of the final derivation.
| for record in run["records"]: | |
| expected = derive(events, record.get("job_id"), evidence["instance_id"]) | |
| if record.get("server_timings") != expected: | |
| raise ValueError("server timings differ from request-correlated raw events") | |
| for record in run["records"]: | |
| expected = derive(events, record.get("job_id"), evidence["instance_id"]) | |
| observed = record.get("server_timings") | |
| if record.get("outcome") in {"timed_out", "transport_error", "interrupted"}: | |
| # The server may emit later stages after the client stops waiting. | |
| later = (expected or {}).get("timestamps_ns", {}) | |
| if observed is not None and any( | |
| value is not None and later.get(name) != value | |
| for name, value in (observed.get("timestamps_ns") or {}).items() | |
| ): | |
| raise ValueError("server timings differ from request-correlated raw events") | |
| elif observed != expected: | |
| raise ValueError("server timings differ from request-correlated raw events") |
| with ThreadPoolExecutor(max_workers=serving["concurrency"]) as pool: | ||
| futures = [pool.submit(attempt, slot, defer_validation=True) for slot in slots if slot["phase"] == "measurement"] | ||
| pending = set(futures) | ||
| while pending: | ||
| try: | ||
| done, _ = wait(pending, timeout=0.1, return_when=FIRST_COMPLETED) | ||
| except KeyboardInterrupt as exc: | ||
| interrupted, abort_reason = exc, "interrupted by operator" | ||
| continue |
There was a problem hiding this comment.
🔴 With --serving-concurrency, Ctrl-C or SIGTERM no longer stops a run promptly. In-flight requests keep polling for up to timeout_seconds (default 3600). The handler at runner.py:827-829 only sets abort_reason and loops again. Worker threads in attempt never look at that flag while polling. An interrupt that lands outside wait() escapes the loop with abort_reason unset, so queued slots still submit and run.json is never finalized. Fix: have the poll loop check a shared stop flag, cancel queued futures, and finalize run.json in a finally on every interrupt path, as the serial path already does.
Why this was flagged
An operator or CI cancel sends SIGTERM during a serving-mode vgbench run --execute. cli.py:68-71 turns it into KeyboardInterrupt in the main thread. In serving mode the main thread is inside wait() at runner.py:826. The handler at :827-829 records interrupted/abort_reason and runs continue. Each worker in attempt (runner.py:741-761) keeps polling until the job ends or deadline = start + timeout_seconds, because it only checks _remaining(deadline) and never abort_reason. If the interrupt lands in future.result(), _event or retain (:832-846), it is not caught. ThreadPoolExecutor.__exit__ then waits for every queued future, and since abort_reason was never set, all remaining measurement slots submit real requests. run_plan then exits without the final run.json write at :868, so compare rejects the bundle as "not finalized". In serial mode the interrupt is raised inside the attempt itself, so the run stops at once and is finalized (runner.py:770-785, 868). A CI runner that sends SIGKILL after a short grace period kills the process before anything is written.
Verification: The handler at runner.py:827-829 only records the interrupt and loops back to wait(). Worker threads running attempt read abort_reason once, before submitting (line 714). --timeout-seconds defaults to 3600 (cli.py:138). Serial mode does not have this problem: there the KeyboardInterrupt is caught at line 770, so it stops promptly.
| result = run_plan( | ||
| plan, | ||
| arguments.output, | ||
| endpoint=arguments.endpoint, | ||
| runtime=arguments.runtime, | ||
| runtime_revision=arguments.runtime_revision, | ||
| hardware_label=arguments.hardware_label, | ||
| model_revision=arguments.model_revision, | ||
| timeout_seconds=arguments.timeout_seconds, | ||
| api_key_env=arguments.api_key_env, | ||
| serving_concurrency=arguments.serving_concurrency, | ||
| delivery_deadline_seconds=arguments.delivery_deadline_seconds, | ||
| ) |
There was a problem hiding this comment.
🔴 Operators comparing same-engine runs of a fairness plan (specs/h3-v0.1.yaml) through vgbench always get exit 2 (inconclusive), and the PSNR/audio thresholds never apply. The CLI has no way to record the server identity that compare.py:643-650 requires before it gates numerical regression. run_plan accepts numerical_identity, but the run_plan(...) call at cli.py:73-85 never passes it. Fix: add a --numerical-identity JSON option, load it with _load_mvp_object, and forward it to run_plan, so that valid_numerical_identity can succeed on CLI-produced bundles.
Why this was flagged
An operator runs vgbench run --execute twice against the same sglang revision and hardware with a plan built from h3-v0.1.yaml, which includes fairness. Then they run vgbench compare. runner.py:655-656 writes configuration["numerical_identity"] only when run_plan gets numerical_identity, and cli.py:73-85 never supplies it (the parser at cli.py:129-141 has no such flag). In compare.py:643, valid_numerical_identity(None, ...) returns False, so numerical_regression is False and diagnostic_quality is True (compare.py:652). Every valid slot therefore gets the inconclusive check quality.cross_engine_or_unmatched (compare.py:668), _fidelity and the policy thresholds are skipped, and cli.py:107 returns 2. The same_configuration_numerical_regression path, exercised only by tests that hand-edit run.json (tests/test_compare.py:215-234), cannot be reached by any repo caller. A real fidelity regression between two same-configuration runs is never reported as fail.
Verification: The run_plan(...) call at cli.py:73-85 never passes numerical_identity, and runner.py:655-656 writes configuration["numerical_identity"] only when it is not None. compare.py:643 calls valid_numerical_identity(None, ...), which returns False at runner.py:96. _fidelity (the PSNR/audio thresholds) never runs, and cli.py:107 maps the inconclusive outcome to exit 2.
| def emit(request_id: str, event: str, **fields) -> None: | ||
| path = os.environ.get("VGBENCH_SERVER_TIMING_PATH") | ||
| if not path: | ||
| return | ||
| timestamp = time.monotonic_ns() | ||
| if not isinstance(request_id, str) or not _SAFE_ID.fullmatch(request_id) or event not in STAGES: | ||
| raise ValueError("invalid H3 server timing event identity") | ||
| value = {"schema_version": VERSION, "request_id": request_id, "event": event, | ||
| "monotonic_ns": timestamp, "clock_id": _clock_id(), "pid": os.getpid(), | ||
| "instance_id": os.environ["VGBENCH_SERVER_TIMING_INSTANCE"], **fields} | ||
| payload = json.dumps(value, sort_keys=True, separators=(",", ":"), allow_nan=False).encode() + b"\n" | ||
| descriptor = os.open(path, os.O_WRONLY | os.O_APPEND | os.O_NOFOLLOW) | ||
| try: | ||
| # One small O_APPEND write per event. The supervisor owns/fsyncs the | ||
| # final ledger; per-request fsync would perturb the measured workload. | ||
| if os.write(descriptor, payload) != len(payload): | ||
| raise OSError("incomplete H3 timing event write") | ||
| finally: | ||
| os.close(descriptor) | ||
|
|
There was a problem hiding this comment.
🟡 (optional) With server timing enabled, a failed timing write turns a good sglang request into an HTTP 500 or a failed video job. emit() raises on any write problem, and the runtime patch calls it inside request and scheduler code without an exception guard. Fix: make every hook-side emit non-fatal (catch OSError, KeyError, ValueError, record the loss as a missing stage, and never raise into sglang), which covers the 4 sites listed. Missing stages already make derive() return partial timings. Same pattern at 4 sites (sglang-71de97b-h3-server-timing.patch:14, :22, :30, runtime_timing.py:89/94). [also at: experimental/video-generation/evaluator/runtime_timing.py:79 - Once the sglang timing patch is applied, a timing-setup mistake makes the server fail every video request or job instead of only losing timing data.]
Why this was flagged
The trigger is any sglang server launched with VGBENCH_SERVER_TIMING_PATH set. At runtime_timing.py:73, os.open uses O_WRONLY|O_APPEND|O_NOFOLLOW without O_CREAT, so a ledger that is missing, rotated or a symlink raises OSError. A full disk or a short write raises at :77-78. If VGBENCH_SERVER_TIMING_INSTANCE is unset, line 69 raises KeyError. The patch calls emit for http_received before the handler's try (patch:22), so the POST /v1/videos fails. The media_ready call sits inside the job's try (patch:14), so a finished video falls into except Exception and is logged as "Video job %s failed". In the scheduler, forward() (runtime_timing.py:85-94) raises around execute_forward. Without the patch, these requests succeed. collect() at :144-155 deliberately keeps the video outcome when timing fails, but nothing gives emit() the same protection.
Verification: In experimental/video-generation/evaluator/runtime_timing.py, emit() has no try/except. Line 72: os.open(path, os.O_WRONLY | os.O_APPEND | os.O_NOFOLLOW) has no O_CREAT, so it raises OSError on a missing file or a symlink. Line 23: vgbench_timing.emit(request_id, "http_received") runs before the handler's try, so the exception escapes and POST /v1/videos returns 500.
| data = stream.read(_MAX_BYTES + 1) | ||
| if len(data) > _MAX_BYTES: | ||
| raise ValueError("server timing ledger exceeds its size bound") |
There was a problem hiding this comment.
🟡 (optional) Once one server launch has handled roughly 2,800 timed requests, every later request's server timing turns invalid, and offline verification rejects the run. Server percentiles go missing even though plans allow up to MAX_SLOTS = 10000 requests. emit appends about 1.5 KB per request (five ~300-byte events) to one per-instance ledger with no bound. read_events raises once the whole file passes _MAX_BYTES (4 MiB). Fix: make the reader handle every ledger the writer can produce. For example, parse it line by line with a per-line cap instead of a whole-file cap, or rotate or scope the ledger per run.
Why this was flagged
Trigger: an operator runs a long or repeated plan (validate_plan allows len(cases) * repetitions + warmup_runs up to MAX_SLOTS = 10000, runner.py:42 and runner.py:251) against one patched sglang launch with VGBENCH_SERVER_TIMING_PATH set. Each request emits five events through emit (runtime_timing.py:61-79), and each line carries clock_id, instance_id, request_id, pid and monotonic_ns, about 300 bytes. Nothing in emit limits the file. After about 4 MiB (around 2,800 requests), read_events raises "server timing ledger exceeds its size bound" (runtime_timing.py:103-104). collect (runtime_timing.py:149-154) swallows that and returns {"status": "invalid"} for every remaining record that runner.py:793 stores. serving.summarize (serving.py:107-127) then withholds all server timing percentiles and batch sizes, and verify_evidence (runtime_timing.py:177) raises for the whole run. The cap only looks like a safeguard: it bounds the reader but not the writer that feeds it.
Verification: validate_plan accepts up to MAX_SLOTS = 10000 requests (runner.py:42, runner.py:246). emit() (runtime_timing.py:61-79) opens the ledger with O_APPEND and appends one JSON line per stage. Nothing limits the file size. read_events() raises at line 103-104 once the whole file passes 4 MiB, and lines 151-154 turn the error into {"status": "invalid"}.
| raise ValueError("server timing ledger hash mismatch") | ||
| for record in run["records"]: | ||
| expected = derive(events, record.get("job_id"), evidence["instance_id"]) | ||
| if record.get("server_timings") != expected: |
There was a problem hiding this comment.
🟡 (optional) If a supervisor uses verify_evidence, a run with any timed-out or interrupted request fails as "server timings differ from request-correlated raw events". The client snapshots collect() when the attempt ends (runner.py:793). The server keeps working after a client timeout and later emits scheduler_dispatch/forward_finished/media_ready. Re-deriving from the final ledger then yields more stages than the snapshot. A transient read error has the same effect: it stores {"status": "invalid"} (line 154), which never equals derive(). Fix: compare strictly only for requests that reached a remote terminal state, and treat snapshots for timed-out or invalid requests as prefixes of the final ledger.
Why this was flagged
Condition: a supervisor calls verify_evidence on a run that used VGBENCH_SERVER_TIMING_PATH. This diff has no non-test caller, so the population cannot be enumerated from here. runner.py:792-793 calls collect(record["job_id"]) in the attempt's finally, right after a client-side timeout or interrupt. At that moment the server may have emitted only http_received/http_accepted. The runner docstring itself says a client timeout does not cancel server work. Later the scheduler patch emits scheduler_dispatch/forward_finished and video_api emits media_ready into the same ledger. runtime_timing.py:181-183 re-runs derive on the final ledger and requires exact equality with the stored snapshot. The required completeness check at :184 only exempts non-succeeded records from the complete requirement, not from this equality check. So the whole run's timing evidence is rejected. collect also turns any OSError or ValueError into {"status": "invalid"} (:150-154), which can never equal derive() output. One transient ledger read failure therefore invalidates the run too.
Verification: The snapshot is taken in the attempt's finally block (runner.py:792-793). verify_evidence re-derives each record from the final ledger and requires exact equality with the stored snapshot (runtime_timing.py:181-183). The required branch (line 184) only demands complete timing for status == "succeeded", but the strict equality on line 182 rejects partial records anyway.
| if names == ["all"]: | ||
| return cases | ||
| known = {case["case_id"] for case in cases} | ||
| if any(Path(name).name != name or name in {".", ".."} for name in known): |
There was a problem hiding this comment.
🟡 (optional) When generating with --case all, a spec case_id like ../x or a/b makes the reference generator write media outside --output. The plain-directory-name check at reference.py:43 runs only after the early return cases for names == ["all"] at line 40. h3_spec only requires case_ids to be nonempty strings. Fix: validate every known case_id (warmup and measured) before the "all" early return, so both selection modes get the same check.
Why this was flagged
The operator runs python -m evaluator.reference --spec <spec> --set <set> --case all without --check. select_cases (reference.py:40-41) returns every case unchecked. h3_spec.py:80 only enforces _text (a nonempty string) on case_id. generate then calls save_media(args.output / case["case_id"], ...). Its directory.mkdir() and np.save/av.open write video.npy, audio.npy and reference.mp4 at the resolved path. For ../x that path is outside the output directory, and none of it is listed in SHA256SUMS (args.output.rglob). The same spec with an explicit --case ../x is rejected with "case IDs must be plain directory names". The guard therefore covers only one of the two selection modes.
Verification: In experimental/video-generation/evaluator/reference.py, select_cases returns early at lines 40-41 before the plain-directory-name guard at line 43. So the guard runs only when cases are chosen by name. _text (specs/h3_spec.py lines 38-40) only requires a nonempty string. A case_id of ../x creates <output>/../x, a sibling of the output directory.
| assert timing.collect("b")["status"] == "complete" | ||
|
|
||
|
|
||
| @pytest.mark.parametrize("defect", ['clock']) |
There was a problem hiding this comment.
🟡 (optional) Four of the five fail-closed timing checks never run, so regressions in duplicate, reversed, instance-mismatch or batch-size rejection would still pass CI. The test is parametrized with only ['clock'], which leaves the duplicate, reverse, instance and batch branches dead. Fix: parametrize with all five defects, e.g. ["duplicate", "clock", "reverse", "instance", "batch"], so every validation rule in derive() is exercised.
Why this was flagged
test_runtime_timing.py:58 declares @ pytest.mark.parametrize("defect", ['clock']), so pytest only ever runs the clock branch at lines 64-65. The branches at lines 62-63 (duplicate), 66-67 (reverse), 68-69 (instance) and 70-71 (observed_batch_size=2) never execute. Suppose derive() at runtime_timing.py:121-124 or :130-131 stopped rejecting duplicate stages, reversed timestamps, instance mismatches or non-singleton batches. CI would stay green, and server timing evidence that should be rejected would be accepted. CONTRIBUTING.md test-quality rules require tests to run the real code on concrete inputs and to use parametrize for sibling cases.
Verification: nit. The trigger is any future regression in derive()'s duplicate, reversed-stage, instance-mismatch or batch-size rejection. tests/test_runtime_timing.py:58 reads @ pytest.mark.parametrize("defect", ['clock']), so only the elif defect == "clock" branch (lines 64-65) ever runs. No other test exercises those rejections. The base has no such guard or test, so nothing regresses at merge.
| @@ -0,0 +1,160 @@ | |||
| """Controlled H3 CI, full-stream comparison, and portable evidence reports.""" | |||
There was a problem hiding this comment.
🟡 nit (optional): Most new modules open with a docstring describing the file, which breaks AGENTS.md "No header comments describing a file"; existing specs/h3_spec.py and tests/test_h3_spec.py have none. sweep:\A""" in experimental/video-generation/evaluator and tests. Examples: cli.py:1 ("Controlled H3 CI, full-stream comparison, and portable evidence reports.") and serving.py:1. Fix: delete these module docstrings and keep only short line-level explanations where needed. [also at: experimental/video-generation/evaluator/runner.py:12 - nit: module docstrings describe whole files, which AGENTS.md "Comments" forbids. sweep:^""" (first line of files in experimental/video-generation/evaluator/).]
Why this was flagged
AGENTS.md lines 54-58 set a mandatory comment rule for every file: "No header comments describing a file, topology, config, recipe, override, or section." Each new module begins with a file-describing docstring: cli.py:1, serving.py:1, compare.py:1-5, media.py:1-6, report.py:1, reference.py:1, runtime_timing.py:1-5, runner.py:1-12, evaluator/init.py:1 and tests/test_runtime_timing.py:1. Nearby existing files such as specs/h3_spec.py and tests/test_h3_spec.py start directly with imports. Some of these headers also carry history, such as runner.py:8-11 "Protocol implementations were inspected at SGLang ...", which the same rule forbids.
Verification: nit. The commit adds new modules that start with file-describing docstrings. AGENTS.md:54-56, which the root CLAUDE.md delegates to, says "No header comments describing a file, topology, config, recipe, override, or section." Examples are cli.py:1 and serving.py:1. The existing specs/h3_spec.py and tests/test_h3_spec.py have no leading docstring. Nothing breaks at runtime.
Summary
Testing:
Validation details
a87f5c32.PR checklist and change type
Type of Change
Checklist
python -m infx.matrix.changed --base origin/mainlists affected config keys, I have appended one new entry covering them to the physical end ofinferencex-e2e/perf-changelog.yaml; if it lists none, I have added none. I have not edited historical entriesinferencex-e2e/perf-changelog.yamlentry, it carries exactly one primary sweep label (a maintainer applies it on fork PRs):full-sweep-fail-fast(recommended),full-sweep-enabled, ornon-canary-full-sweep-enabled. Optional modifiersall-evals,evals-only, andagentx-fastrequire a primary label; the last two block reuse while applied.OWNER/MEMBER/COLLABORATOR) has commented/use <run_id>(or the legacy/reuse-sweep-run) on this PR. Do this only once there is a final full sweep that is all green with evals passing, since after this comment the primary sweep label will no longer automatically kick off new sweeps. Remove and re-add the primary sweep label to force a new sweep.