From 08365c7df5309c4108bc92d5c294d790d16b677b Mon Sep 17 00:00:00 2001 From: Chris Dumas Date: Sat, 29 Aug 2026 00:22:48 +0000 Subject: [PATCH] Add long videos timing breakdown --- dumas_h3_longvideos.py | 225 ++++++++++++++++++++++-------- tests/test_dumas_h3_longvideos.py | 35 +++++ 2 files changed, 202 insertions(+), 58 deletions(-) diff --git a/dumas_h3_longvideos.py b/dumas_h3_longvideos.py index d5a8b1c..ad22b9d 100644 --- a/dumas_h3_longvideos.py +++ b/dumas_h3_longvideos.py @@ -43,11 +43,12 @@ ldm/minimax/model.py, text_encoders/minimax.py, sd.py). import gc from functools import lru_cache import json -import logging -import math -import os -import re -import torch +import logging +import math +import os +import re +import time +import torch import nodes import comfy.utils @@ -4073,6 +4074,65 @@ def _coerce_bool_flag(value): if text in ("1", "true", "yes", "on"): return True return bool(value) + + +def _format_elapsed_seconds(seconds): + seconds = max(0.0, float(seconds or 0.0)) + if seconds >= 3600: + hours = int(seconds // 3600) + minutes = int((seconds % 3600) // 60) + secs = seconds % 60 + return f"{hours}h{minutes:02d}m{secs:04.1f}s" + if seconds >= 60: + minutes = int(seconds // 60) + secs = seconds % 60 + return f"{minutes}m{secs:04.1f}s" + return f"{seconds:0.1f}s" + + +def _format_timing_note(shot_timings): + if not shot_timings: + return "" + totals = { + "total": 0.0, + "retry_elapsed": 0.0, + "sample": 0.0, + "detail_sample": 0.0, + "decode_video": 0.0, + "decode_audio": 0.0, + "cleanup": 0.0, + "retries": 0, + } + slowest = None + for shot in shot_timings: + totals["total"] += float(shot.get("total", 0.0) or 0.0) + totals["retry_elapsed"] += float(shot.get("retry_elapsed", 0.0) or 0.0) + totals["sample"] += float(shot.get("sample", 0.0) or 0.0) + totals["detail_sample"] += float(shot.get("detail_sample", 0.0) or 0.0) + totals["decode_video"] += float(shot.get("decode_video", 0.0) or 0.0) + totals["decode_audio"] += float(shot.get("decode_audio", 0.0) or 0.0) + totals["cleanup"] += float(shot.get("cleanup", 0.0) or 0.0) + totals["retries"] += max(0, int(shot.get("attempts", 1) or 1) - 1) + if slowest is None or float(shot.get("total", 0.0) or 0.0) > float(slowest.get("total", 0.0) or 0.0): + slowest = shot + pieces = [ + f"timing: {len(shot_timings)} shot(s) total {_format_elapsed_seconds(totals['total'])}", + f"sample {_format_elapsed_seconds(totals['sample'])}", + f"decode video {_format_elapsed_seconds(totals['decode_video'])}", + f"decode audio {_format_elapsed_seconds(totals['decode_audio'])}", + f"cleanup {_format_elapsed_seconds(totals['cleanup'])}", + ] + if totals["retry_elapsed"]: + pieces.append(f"retry elapsed {_format_elapsed_seconds(totals['retry_elapsed'])}") + if totals["detail_sample"]: + pieces.append(f"detail {_format_elapsed_seconds(totals['detail_sample'])}") + if totals["retries"]: + pieces.append(f"retries {totals['retries']}") + if slowest is not None: + pieces.append( + f"slowest shot {int(slowest.get('shot', 0) or 0)} {_format_elapsed_seconds(slowest.get('total', 0.0))}" + ) + return "; ".join(pieces) # --- ref2va reference conditioning ---------------------------------------- @@ -6300,23 +6360,26 @@ class H3LongVideos: handoff, decode_tile_frames=0, decode_tile_size=0, refs=None, ref_image_size="match", ref_noise_aug=None, silent=False, detail_pass=False, detail_sampler_name="euler", detail_scheduler="beta", - detail_steps=8, detail_denoise=0.4): + detail_steps=8, detail_denoise=0.4, timing_sink=None): + timing = {"sample": 0.0, "detail_sample": 0.0, "decode_video": 0.0, "decode_audio": 0.0, "cleanup": 0.0} positive, latent = _build_shot_conditioning(clip, vae, prompt, w, h, ln, fps, handoff, ref_images=refs, ref_image_size=ref_image_size, ref_noise_aug=ref_noise_aug, audio_vae=audio_vae, silent=silent) seed, steps, cfg, sn, sch, denoise = sa - # Conditioning is built, so the text encoder and VAEs are dead weight for the - # whole sampling loop -- evict them and keep only the DiT on the card. - _evict_all_but(model) + # Conditioning is built, so the text encoder and VAEs are dead weight for the + # whole sampling loop -- evict them and keep only the DiT on the card. + _evict_all_but(model) try: + sample_start = time.perf_counter() (out,) = nodes.common_ksampler(model, seed, steps, cfg, sn, sch, positive, negative, latent, denoise=denoise) + timing["sample"] += time.perf_counter() - sample_start except Exception as e: - # Mark WHERE this failed. `tiled` only affects the DECODE, so the caller's - # OOM retry cannot help an OOM raised here -- it just re-runs the whole - # sampling pass and fails the same way, which on a 362-frame shot is four - # more minutes for nothing. + # Mark WHERE this failed. `tiled` only affects the DECODE, so the caller's + # OOM retry cannot help an OOM raised here -- it just re-runs the whole + # sampling pass and fails the same way, which on a 362-frame shot is four + # more minutes for nothing. if _is_oom(e): e._h3_stage = "sampling" raise @@ -6325,9 +6388,11 @@ class H3LongVideos: if detail_pass: detail_latent = _latent_with_replaced_samples(latent, out) try: + detail_start = time.perf_counter() (refined_out,) = nodes.common_ksampler( model, seed, int(detail_steps), cfg, detail_sampler_name, detail_scheduler, positive, negative, detail_latent, denoise=float(detail_denoise)) + timing["detail_sample"] += time.perf_counter() - detail_start except Exception as e: if _is_oom(e): e._h3_stage = "sampling" @@ -6338,12 +6403,21 @@ class H3LongVideos: # 1344x768 124f shot is ~1.5MB against ~1.5GB), so carrying one per shot for # the whole chain is free. Detached and moved off the card immediately, for # the same reason the decoded frames are. + decode_video_start = time.perf_counter() shot_latent = _copy_sample_latent(refined_out) video = _decode_video(vae, refined_out, tiled, free_first=model, tile_t=decode_tile_frames, tile_xy=decode_tile_size) + timing["decode_video"] += time.perf_counter() - decode_video_start + decode_audio_start = time.perf_counter() audio = _decode_audio(audio_vae, out) + timing["decode_audio"] += time.perf_counter() - decode_audio_start + cleanup_start = time.perf_counter() del out, refined_out, positive, latent _deep_cleanup() + timing["cleanup"] += time.perf_counter() - cleanup_start + if timing_sink is not None: + timing["total"] = sum(timing.values()) + timing_sink.append(timing) return video, audio, shot_latent def run(self, model, clip, vae, audio_vae, prompt, resolution, @@ -6788,7 +6862,7 @@ class H3LongVideos: backoff, video_chunks, audio_chunks = [], [], [] latent_chunks = [] # per-shot sampled latents, pre-decode mouth_settled = [] # shots seeded from a settled (closed) mouth - handoff, sr = first_frame, None + handoff, sr = first_frame, None connected_ref_count = len(connected_refs) ref_shots = [] # which shots ended up ref-conditioned ref_missing = [] # tags naming an unconnected slot @@ -6797,6 +6871,7 @@ class H3LongVideos: ref_mode_used = [] continuity_used = [] ref_aug_used = [] + shot_timings = [] if cleanup_between_shots: _deep_cleanup() # start the first (heaviest) shot with max free VRAM @@ -6905,49 +6980,81 @@ class H3LongVideos: ref_aug_used.append(shot_aug) if shot_refs: ref_shots.append(i + 1) + shot_total_start = time.perf_counter() + shot_retry_elapsed = 0.0 + shot_attempts = 0 + shot_timing = [] if i == 0: while True: + shot_attempts += 1 + attempt_start = time.perf_counter() try: - frames, audio, shot_latent = self._render(model, clip, vae, audio_vae, negative, gen_prompt, w, h, ln_i, fps, tiled, sa, shot_handoff, decode_tile_frames, decode_tile_size, - shot_refs, ref_image_size, shot_aug, shot_silent, - detail_pass, detail_sampler_name, detail_scheduler, - detail_steps, detail_denoise) - break - except (torch.cuda.OutOfMemoryError, RuntimeError) as e: - if not _is_oom(e): - raise - mm.soft_empty_cache(True) - if not tiled: - tiled = True; backoff.append("tiled decode") + frames, audio, shot_latent = self._render( + model, clip, vae, audio_vae, negative, gen_prompt, w, h, ln_i, fps, + tiled, sa, shot_handoff, decode_tile_frames, decode_tile_size, + shot_refs, ref_image_size, shot_aug, shot_silent, + detail_pass, detail_sampler_name, detail_scheduler, + detail_steps, detail_denoise, timing_sink=shot_timing) + break + except (torch.cuda.OutOfMemoryError, RuntimeError) as e: + shot_retry_elapsed += time.perf_counter() - attempt_start + if not _is_oom(e): + raise + mm.soft_empty_cache(True) + if not tiled: + tiled = True; backoff.append("tiled decode") elif allow_res_backoff and min(w, h) > 384: nw, nh = res_down(w, h); backoff.append(f"res->{nw}x{nh}"); w, h = nw, nh else: - raise RuntimeError("H3 Long Videos: not enough VRAM even at the smallest size. " - "Pick a smaller resolution, close other GPU apps, or use a smaller quant.") - else: + raise RuntimeError("H3 Long Videos: not enough VRAM even at the smallest size. " + "Pick a smaller resolution, close other GPU apps, or use a smaller quant.") + else: try: - frames, audio, shot_latent = self._render(model, clip, vae, audio_vae, negative, gen_prompt, w, h, ln_i, fps, tiled, sa, shot_handoff, decode_tile_frames, decode_tile_size, - shot_refs, ref_image_size, shot_aug, shot_silent, - detail_pass, detail_sampler_name, detail_scheduler, - detail_steps, detail_denoise) - except (torch.cuda.OutOfMemoryError, RuntimeError) as e: - if _is_oom(e) and getattr(e, "_h3_stage", "") == "sampling": - # Retrying with tiles would re-run the whole sampling pass and - # fail identically. Fail now, and say what actually shrinks it. - raise RuntimeError( - f"H3 Long Videos: shot {i + 1} of {len(gens)} ran out of VRAM " - f"while sampling. " + sampling_oom_help(w, h, ln_i, fps, megapixels) - ) from e - if not _is_oom(e) or tiled: - raise + shot_attempts += 1 + attempt_start = time.perf_counter() + frames, audio, shot_latent = self._render( + model, clip, vae, audio_vae, negative, gen_prompt, w, h, ln_i, fps, + tiled, sa, shot_handoff, decode_tile_frames, decode_tile_size, + shot_refs, ref_image_size, shot_aug, shot_silent, + detail_pass, detail_sampler_name, detail_scheduler, + detail_steps, detail_denoise, timing_sink=shot_timing) + except (torch.cuda.OutOfMemoryError, RuntimeError) as e: + shot_retry_elapsed += time.perf_counter() - attempt_start + if _is_oom(e) and getattr(e, "_h3_stage", "") == "sampling": + # Retrying with tiles would re-run the whole sampling pass and + # fail identically. Fail now, and say what actually shrinks it. + raise RuntimeError( + f"H3 Long Videos: shot {i + 1} of {len(gens)} ran out of VRAM " + f"while sampling. " + sampling_oom_help(w, h, ln_i, fps, megapixels) + ) from e + if not _is_oom(e) or tiled: + raise mm.soft_empty_cache(True); tiled = True; backoff.append(f"shot {i+1}: tiled") - frames, audio, shot_latent = self._render(model, clip, vae, audio_vae, negative, gen_prompt, w, h, ln_i, fps, tiled, sa, shot_handoff, decode_tile_frames, decode_tile_size, - shot_refs, ref_image_size, shot_aug, shot_silent, - detail_pass, detail_sampler_name, detail_scheduler, - detail_steps, detail_denoise) - - if shot_latent is not None: - latent_chunks.append(shot_latent) + shot_attempts += 1 + attempt_start = time.perf_counter() + frames, audio, shot_latent = self._render( + model, clip, vae, audio_vae, negative, gen_prompt, w, h, ln_i, fps, + tiled, sa, shot_handoff, decode_tile_frames, decode_tile_size, + shot_refs, ref_image_size, shot_aug, shot_silent, + detail_pass, detail_sampler_name, detail_scheduler, + detail_steps, detail_denoise, timing_sink=shot_timing) + shot_retry_elapsed += time.perf_counter() - attempt_start + + shot_total = time.perf_counter() - shot_total_start + if shot_timing: + render_timing = dict(shot_timing[-1]) + else: + render_timing = {} + shot_timings.append({ + "shot": i + 1, + "total": shot_total, + "retry_elapsed": shot_retry_elapsed, + "attempts": shot_attempts, + **render_timing, + }) + + if shot_latent is not None: + latent_chunks.append(shot_latent) sr = audio["sample_rate"]; wav = audio["waveform"] # End the shot `hoff` frames early so the frame handed to the NEXT shot @@ -7181,11 +7288,12 @@ class H3LongVideos: + (f" (source {direct_ref_count} direct)" if direct_ref_count else "")) else: ref_note = "" - info = ((anchor_note + " ") if anchor_note else "") + \ - (f"{shape_str} at {w}x{h}; {all_frames.shape[0]} frames (~{actual:.1f}s actual). " - f"decode {'tiled' if tiled else 'full'}. {vram_str}.{hoff_str}" - + (" DIALOGUE MAY BE CUT OFF -- " + "; ".join(fit_warnings) - + ". Shorten the line, or pick a lower resolution tier to keep the duration." + timing_note = _format_timing_note(shot_timings) + info = ((anchor_note + " ") if anchor_note else "") + \ + (f"{shape_str} at {w}x{h}; {all_frames.shape[0]} frames (~{actual:.1f}s actual). " + f"decode {'tiled' if tiled else 'full'}. {vram_str}.{hoff_str}" + + (" DIALOGUE MAY BE CUT OFF -- " + "; ".join(fit_warnings) + + ". Shorten the line, or pick a lower resolution tier to keep the duration." if fit_warnings else "") + ((" subject-count guard ON (" + ("sub-native resolution" if min(w, h) < 768 else "") @@ -7209,11 +7317,12 @@ class H3LongVideos: + (" OVERRIDES -- " + "; ".join(override_notes) + "." if override_notes else "") + (f"{ref_note}." if ref_note else "") + + (f" {timing_note}." if timing_note else "") + (f" {fps_note}." if fps_note else "") - + (f" {swap_note}." if swap_note else "") - + (f" free VRAM/shot: {vram_trace}." if len(vram_trace) > 1 else "") - + (f" {accel_note}." if accel_note else "") - + (f" {ms_note}." if ms_note else "") + + (f" {swap_note}." if swap_note else "") + + (f" free VRAM/shot: {vram_trace}." if len(vram_trace) > 1 else "") + + (f" {accel_note}." if accel_note else "") + + (f" {ms_note}." if ms_note else "") + (f" {ln_note}." if ln_note else "") + (f" {up_note}." if up_note else "") + (f" {ov_note}." if ov_note else "") diff --git a/tests/test_dumas_h3_longvideos.py b/tests/test_dumas_h3_longvideos.py index 21bcf79..01610be 100644 --- a/tests/test_dumas_h3_longvideos.py +++ b/tests/test_dumas_h3_longvideos.py @@ -160,6 +160,41 @@ class DumasH3LongVideosHelperTests(unittest.TestCase): "keyframe carry", ) + def test_timing_summary_reports_retry_and_bucket_totals(self): + note = self.module._format_timing_note([ + { + "shot": 1, + "total": 12.4, + "retry_elapsed": 1.2, + "attempts": 2, + "sample": 8.0, + "detail_sample": 0.5, + "decode_video": 2.1, + "decode_audio": 0.4, + "cleanup": 0.2, + }, + { + "shot": 2, + "total": 7.6, + "retry_elapsed": 0.0, + "attempts": 1, + "sample": 6.5, + "decode_video": 0.5, + "decode_audio": 0.3, + "cleanup": 0.1, + }, + ]) + + self.assertIn("timing: 2 shot(s) total 20.0s", note) + self.assertIn("sample 14.5s", note) + self.assertIn("decode video 2.6s", note) + self.assertIn("decode audio 0.7s", note) + self.assertIn("cleanup 0.3s", note) + self.assertIn("retry elapsed 1.2s", note) + self.assertIn("detail 0.5s", note) + self.assertIn("retries 1", note) + self.assertIn("slowest shot 1 12.4s", note) + def test_detail_pass_refines_video_but_preserves_audio(self): class FakeTensor: def __init__(self, name):