Add per-phase timing to pipeline call and text_encoder offload

The existing vae_decode timing bucket (last_step -> pipe_end) lumps
together the text_encoder CPU offload, latent unpacking, actual VAE
decode, and postprocessing, making it look like decode itself is slow.
Split each phase out with its own timestamped log line so the real
cost can be seen directly instead of inferred.

app.py

@@ -545,8 +545,11 @@ def _make_step_callback(steps, timer, t0):
         # accelerate hooks are managing placement (offload-fallback path) to avoid
         # fighting their own device bookkeeping — see the finally block below.
         if step_idx == steps - 1 and getattr(pipeline.text_encoder, "_hf_hook", None) is None:
+            _offload_t0 = time.perf_counter()
             pipeline.text_encoder.to("cpu")
             torch.cuda.empty_cache()
+            _offload_ms = (time.perf_counter() - _offload_t0) * 1000
+            print(f"[infer] text_encoder offload to cpu — {_offload_ms:.0f}ms | t={time.perf_counter()-t0:.1f}s")
         delta_ms = (now - (step_times[-2] if len(step_times) > 1 else t0)) * 1000
         tag = " ← includes cold-start (offload hook install + first weight transfer)" if step_idx == 0 else ""
         print(f"[infer] step {step_idx+1}/{steps} done — {delta_ms:.0f}ms{tag} | t={now-t0:.1f}s")

qwenimage/pipeline_qwenimage_edit_plus.py

@@ -14,6 +14,7 @@
 
 import inspect
 import math
+import time
 from typing import Any, Callable, Dict, List, Optional, Union
 
 import numpy as np
@@ -664,6 +665,19 @@ class QwenImageEditPlusPipeline(DiffusionPipeline, QwenImageLoraLoaderMixin):
             batch_size = prompt_embeds.shape[0]
 
         device = self._execution_device
+
+        # Per-phase timing, independent of app.py's step-level instrumentation — isolates
+        # where GPU time actually goes inside a single pipeline call (image/text encoding,
+        # denoising loop, VAE decode, postprocess) instead of lumping everything after the
+        # last denoising step into one opaque "vae_decode" bucket.
+        _phase_t0 = time.perf_counter()
+        _phase_last = [_phase_t0]
+
+        def _mark(label):
+            now = time.perf_counter()
+            print(f"[pipe] {label} — {(now - _phase_last[0]) * 1000:.0f}ms | t={now - _phase_t0:.1f}s", flush=True)
+            _phase_last[0] = now
+
         # 3. Preprocess image
         if image is not None and not (isinstance(image, torch.Tensor) and image.size(1) == self.latent_channels):
             if not isinstance(image, list):
@@ -682,6 +696,7 @@ class QwenImageEditPlusPipeline(DiffusionPipeline, QwenImageLoraLoaderMixin):
                 vae_image_sizes.append((vae_width, vae_height))
                 condition_images.append(self.image_processor.resize(img, condition_height, condition_width))
                 vae_images.append(self.image_processor.preprocess(img, vae_height, vae_width).unsqueeze(2))
+        _mark("image_preprocess")
 
         has_neg_prompt = negative_prompt is not None or (
             negative_prompt_embeds is not None and negative_prompt_embeds_mask is not None
@@ -716,6 +731,7 @@ class QwenImageEditPlusPipeline(DiffusionPipeline, QwenImageLoraLoaderMixin):
                 num_images_per_prompt=num_images_per_prompt,
                 max_sequence_length=max_sequence_length,
             )
+        _mark("encode_prompt")
 
         # 4. Prepare latent variables
         num_channels_latents = self.transformer.config.in_channels // 4
@@ -730,6 +746,7 @@ class QwenImageEditPlusPipeline(DiffusionPipeline, QwenImageLoraLoaderMixin):
             generator,
             latents,
         )
+        _mark("prepare_latents (incl. condition-image VAE encode)")
         img_shapes = [
             [
                 (1, height // self.vae_scale_factor // 2, width // self.vae_scale_factor // 2),
@@ -791,6 +808,7 @@ class QwenImageEditPlusPipeline(DiffusionPipeline, QwenImageLoraLoaderMixin):
             )
         else:
             uncond_image_rotary_emb = None
+        _mark("timesteps_and_rope_setup")
 
         # 6. Denoising loop
         self.scheduler.set_begin_index(0)
@@ -863,6 +881,7 @@ class QwenImageEditPlusPipeline(DiffusionPipeline, QwenImageLoraLoaderMixin):
 
                 if XLA_AVAILABLE:
                     xm.mark_step()
+        _mark("denoise_loop")
 
         self._current_timestep = None
         if output_type == "latent":
@@ -879,11 +898,15 @@ class QwenImageEditPlusPipeline(DiffusionPipeline, QwenImageLoraLoaderMixin):
                 latents.device, latents.dtype
             )
             latents = latents / latents_std + latents_mean
+            _mark("unpack_and_upcast_latents")
             image = self.vae.decode(latents, return_dict=False)[0][:, :, 0]
+            _mark("vae_decode")
             image = self.image_processor.postprocess(image, output_type=output_type)
+            _mark("postprocess")
 
         # Offload all models
         self.maybe_free_model_hooks()
+        _mark("free_model_hooks")
 
         if not return_dict:
             return (image,)