Pipeline stage P1: shape-level profile diagnostic, flash-attn K packing once per head, build.sh submodule reset fix

README.md

@@ -56,6 +56,12 @@ n = 2 run(s) per row (median). Speedup = stock-Q4_K generate time / row generate
 - 「像素差」只對**權重相同**的列有意義。第 6 列與第 1 列完全相同，表示 FFN 融合沒有改變輸出。第 5、7 列是 AMX 的數值差異（平均差 1.28），視覺上與 stock 相同。Q4_0、Q8_0 使用不同權重，差異大是預期的，不代表品質問題。
 - AVX2 與 AVX512 的輸出與 stock 不同，原因是浮點運算順序不同。
 
+## Pipeline 階段 P1：flash-attn K 打包（已完成，優先執行）
+
+先量測而非猜測：矩陣乘在 pipeline 內與微基準一致，沒有額外開銷；pipeline 的額外開銷是非矩陣乘部分（約 1.4 s/步），主要是 flash-attn。
+把 K 的轉置打包改為每個頭只做一次，FLASH_ATTN 從 1607 ms 降到 1226 ms（-24%），輸出與修改前逐像素相同。
+詳見 `stages/stage_p1_pipe/README.md`。
+
 ## 第一階段：VAE 解碼（已完成）
 
 OpenVINO 的 VAE 解碼約 0.55 s，sd.cpp 約 10 s。第一階段嘗試了 conv-direct、VAE tiling、F16 VAE 權重與 llamafile sgemm。

build.sh

@@ -123,6 +123,8 @@ if [[ ${#SELECTED[@]} -gt 0 ]]; then
     git -C "$SRC" checkout -q -f "$SDCPP_REF"
     git -C "$SRC" reset -q --hard "$SDCPP_REF"
     git -C "$SRC" submodule update -q --init --recursive
+    # discard leftovers of earlier patch runs so the patches below always apply to the pinned sources
+    git -C "$SRC" submodule foreach -q --recursive 'git checkout -q -- . 2>/dev/null || true'
 
     # Apply our patches (idempotent: skip a patch that is already applied).
     apply_patch() {
@@ -137,6 +139,7 @@ if [[ ${#SELECTED[@]} -gt 0 ]]; then
     }
     apply_patch "$SRC"        "$ROOT/patches/sdcpp-0001-zimage-ffn-w13-and-cpu-extra-buft.patch"
     apply_patch "$SRC/ggml"   "$ROOT/patches/ggml-0001-cpu-op-profile.patch"
+    apply_patch "$SRC/ggml"   "$ROOT/patches/ggml-0002-flash-attn-kpack.patch"
 
     # ------------------------------------------------------------ build
     for v in "${SELECTED[@]}"; do

patches/ggml-0001-cpu-op-profile.patch

@@ -1,8 +1,8 @@
 diff --git a/src/ggml-cpu/ggml-cpu.c b/src/ggml-cpu/ggml-cpu.c
-index fd55589f..42a4c789 100644
+index fd55589f..4c3575ff 100644
 --- a/src/ggml-cpu/ggml-cpu.c
 +++ b/src/ggml-cpu/ggml-cpu.c
-@@ -3235,6 +3235,21 @@ struct ggml_cplan ggml_graph_plan(
+@@ -3235,6 +3235,47 @@ struct ggml_cplan ggml_graph_plan(
  // Returns the number of nodes skipped by fusion (>=1), or 0 if no fusion was applied.
  static bool ggml_cpu_disable_fusion = false;  // initialized once in ggml_cpu_init(), read-only afterwards
  
@@ -10,6 +10,32 @@ index fd55589f..42a4c789 100644
 +static bool    ggml_cpu_profile_enabled = false;
 +static double  ggml_cpu_prof_us[GGML_OP_COUNT + 1];
 +static int64_t ggml_cpu_prof_n[GGML_OP_COUNT + 1];
++// shape-level MUL_MAT profile (GGML_CPU_PROFILE=2): key = K,N,M, src0 buffer kind, src1 contiguity
++#define GGML_CPU_PROF_MM_MAX 128
++struct ggml_cpu_prof_mm_entry { int64_t k, n, m; int buf; int contig; double us; int64_t cnt; int used; };
++static struct ggml_cpu_prof_mm_entry ggml_cpu_prof_mm[GGML_CPU_PROF_MM_MAX];
++static bool ggml_cpu_profile_shapes = false;
++static void ggml_cpu_prof_mm_add(const struct ggml_tensor * t, double us) {
++    const int buf = (t->src[0]->buffer && t->src[0]->buffer->buft && strcmp(ggml_backend_buft_name(t->src[0]->buffer->buft), "AMX") == 0) ? 1 :
++                    (t->src[0]->buffer && t->src[0]->buffer->buft && strstr(ggml_backend_buft_name(t->src[0]->buffer->buft), "REPACK")) ? 2 : 0;
++    const int contig = ggml_is_contiguous(t->src[1]) ? 1 : 0;
++    const int64_t k = t->src[0]->ne[0], n = t->src[0]->ne[1], m = t->src[1]->ne[1];
++    for (int i = 0; i < GGML_CPU_PROF_MM_MAX; ++i) {
++        struct ggml_cpu_prof_mm_entry * e = &ggml_cpu_prof_mm[i];
++        if (!e->used) { e->used = 1; e->k = k; e->n = n; e->m = m; e->buf = buf; e->contig = contig; }
++        if (e->k == k && e->n == n && e->m == m && e->buf == buf && e->contig == contig) { e->us += us; e->cnt++; return; }
++    }
++}
++static void ggml_cpu_profile_dump_shapes(void) {
++    fprintf(stderr, "PROFMM K N M buf contig calls total_ms per_call_ms\n");
++    for (int i = 0; i < GGML_CPU_PROF_MM_MAX; ++i) {
++        struct ggml_cpu_prof_mm_entry * e = &ggml_cpu_prof_mm[i];
++        if (!e->used) continue;
++        fprintf(stderr, "PROFMM %lld %lld %lld %s %d %lld %.1f %.3f\n", (long long)e->k, (long long)e->n, (long long)e->m,
++                e->buf == 1 ? "AMX" : e->buf == 2 ? "REPACK" : "default", e->contig, (long long)e->cnt, e->us / 1000.0, e->us / 1000.0 / (double)e->cnt);
++    }
++}
++
 +static void ggml_cpu_profile_dump(void) {
 +    double total = 0;
 +    for (int i = 0; i <= GGML_OP_COUNT; i++) total += ggml_cpu_prof_us[i];
@@ -24,7 +50,7 @@ index fd55589f..42a4c789 100644
  static int ggml_cpu_try_fuse_ops(
          const struct ggml_cgraph * cgraph,
          const int node_n,
-@@ -3311,6 +3326,8 @@ static thread_ret_t ggml_graph_compute_thread(void * data) {
+@@ -3311,6 +3352,8 @@ static thread_ret_t ggml_graph_compute_thread(void * data) {
  
          // TODO: move fused-op detection into ggml_graph_plan so fusion decisions are made once at planning time
          // Try fused ops, fall back to normal compute
@@ -33,7 +59,7 @@ index fd55589f..42a4c789 100644
          const int n_fused = ggml_cpu_try_fuse_ops(cgraph, node_n, &params, cplan);
          if (n_fused > 0) {
              node_n += n_fused;
-@@ -3327,6 +3344,11 @@ static thread_ret_t ggml_graph_compute_thread(void * data) {
+@@ -3327,6 +3370,14 @@ static thread_ret_t ggml_graph_compute_thread(void * data) {
          if (node_n + 1 < cgraph->n_nodes) {
              ggml_barrier(state->threadpool);
          }
@@ -41,19 +67,26 @@ index fd55589f..42a4c789 100644
 +            const int idx = n_fused > 0 ? GGML_OP_COUNT : (int) node->op;
 +            ggml_cpu_prof_us[idx] += (double) (ggml_time_us() - prof_t0);
 +            ggml_cpu_prof_n[idx]  += 1;
++            if (ggml_cpu_profile_shapes && node->op == GGML_OP_MUL_MAT && n_fused == 0) {
++                ggml_cpu_prof_mm_add(node, (double) (ggml_time_us() - prof_t0));
++            }
 +        }
      }
  
  #ifdef GGML_USE_OPENMP
-@@ -4105,6 +4127,13 @@ void ggml_cpu_init(void) {
+@@ -4105,6 +4156,17 @@ void ggml_cpu_init(void) {
              const char * env = getenv("GGML_CPU_DISABLE_FUSION");
              ggml_cpu_disable_fusion = (env != NULL && atoi(env) == 1);
          }
 +        {
 +            const char * env = getenv("GGML_CPU_PROFILE");
-+            if (env != NULL && atoi(env) == 1) {
++            if (env != NULL && (atoi(env) == 1 || atoi(env) == 2)) {
 +                ggml_cpu_profile_enabled = true;
 +                atexit(ggml_cpu_profile_dump);
++                if (atoi(env) == 2) {
++                    ggml_cpu_profile_shapes = true;
++                    atexit(ggml_cpu_profile_dump_shapes);
++                }
 +            }
 +        }
  

patches/ggml-0002-flash-attn-kpack.patch

@@ -0,0 +1,97 @@
+diff --git a/src/ggml-cpu/ops.cpp b/src/ggml-cpu/ops.cpp
+index e8ef14f2..8a155984 100644
+--- a/src/ggml-cpu/ops.cpp
++++ b/src/ggml-cpu/ops.cpp
+@@ -9238,10 +9238,20 @@ static void ggml_compute_forward_flash_attn_ext_f16_one_chunk(
+     }
+ }
+ 
++// Stage P1 (pipeline): per-thread cache of the transposed, KV-tile-packed K for the current head.
++// The tiled kernel used to re-pack K for every (Q tile, KV tile) pair; now each head is packed once per
++// thread and reused by all Q tiles of that head. The cache is reset at every call of the tiled kernel,
++// so it never survives a graph execution (buffers are reused across graphs and their contents change).
++struct fa_kpack_key { const void * data; int64_t ik2, ik3, nek1, nbk1, nbk2, nbk3; };
++static thread_local std::vector<float> fa_kpack_buf;
++static thread_local fa_kpack_key       fa_kpack_cur;
++static thread_local bool               fa_kpack_valid = false;
++
+ static void ggml_compute_forward_flash_attn_ext_tiled(
+         const ggml_compute_params * params,
+         ggml_tensor * dst,
+         int ir0, int ir1) {
++    fa_kpack_valid = false;  // new chunk: K contents may differ from the previous call
+     const ggml_tensor * q     = dst->src[0];
+     const ggml_tensor * k     = dst->src[1];
+     const ggml_tensor * v     = dst->src[2];
+@@ -9381,6 +9391,43 @@ static void ggml_compute_forward_flash_attn_ext_tiled(
+         memset(K_f32, 0, DK * KV_TILE_SZ * sizeof(float));
+         memset(V32,   0, KV_TILE_SZ * DV * sizeof(float));
+ 
++        // packed K for this head: [n_kv_tiles][DK][KV_TILE_SZ], zero-padded last tile
++        const float * kpack = nullptr;
++        {
++            const fa_kpack_key key{ k->data, ik2, ik3, nek1, nbk1, nbk2, nbk3 };
++            const int64_t n_kv_tiles = (nek1 + KV_TILE_SZ - 1) / KV_TILE_SZ;
++            const size_t  need       = (size_t) (n_kv_tiles * DK * KV_TILE_SZ);
++            if (!fa_kpack_valid || memcmp(&key, &fa_kpack_cur, sizeof(key)) != 0 || fa_kpack_buf.size() < need) {
++                if (fa_kpack_buf.size() < need) {
++                    fa_kpack_buf.resize(need);
++                }
++                float * dst_pack = fa_kpack_buf.data();
++                for (int64_t t = 0; t < n_kv_tiles; t++) {
++                    float * tile = dst_pack + t * DK * KV_TILE_SZ;
++                    const int64_t base_k = t * KV_TILE_SZ;
++                    const int kv_tile_n  = (int) std::min((int64_t)KV_TILE_SZ, nek1 - base_k);
++                    memset(tile, 0, DK * KV_TILE_SZ * sizeof(float));
++                    for (int tk = 0; tk < kv_tile_n; tk++) {
++                        const char * k_data = (const char *)k->data + (base_k + tk)*nbk1 + ik2*nbk2 + ik3*nbk3;
++                        if (kv_type == GGML_TYPE_F16) {
++                            const ggml_fp16_t * k_f16 = (const ggml_fp16_t *)k_data;
++                            for (int64_t dk = 0; dk < DK; dk++) {
++                                tile[dk * KV_TILE_SZ + tk] = GGML_CPU_FP16_TO_FP32(k_f16[dk]);
++                            }
++                        } else {
++                            const float * k_f32_src = (const float *)k_data;
++                            for (int64_t dk = 0; dk < DK; dk++) {
++                                tile[dk * KV_TILE_SZ + tk] = k_f32_src[dk];
++                            }
++                        }
++                    }
++                }
++                fa_kpack_cur   = key;
++                fa_kpack_valid = true;
++            }
++            kpack = fa_kpack_buf.data();
++        }
++
+         for (int64_t ic = 0; ic < nek1; ic += KV_TILE_SZ) {
+             const int kv_tile = (int)std::min((int64_t)KV_TILE_SZ, nek1 - ic);
+ 
+@@ -9406,24 +9453,10 @@ static void ggml_compute_forward_flash_attn_ext_tiled(
+                 }
+             }
+ 
+-            // Pack K tile transposed: K_f32[dk][kv] so KV_TILE is contiguous (SIMD dim)
+-            // Zero-pad the last tile so the GEMM always operates on KV_TILE_SZ columns
+-            for (int tk = 0; tk < kv_tile; tk++) {
+-                const char * k_data = (const char *)k->data + (ic + tk)*nbk1 + ik2*nbk2 + ik3*nbk3;
+-                if (kv_type == GGML_TYPE_F16) {
+-                    const ggml_fp16_t * k_f16 = (const ggml_fp16_t *)k_data;
+-                    for (int64_t dk = 0; dk < DK; dk++) {
+-                        K_f32[dk * KV_TILE_SZ + tk] = GGML_CPU_FP16_TO_FP32(k_f16[dk]);
+-                    }
+-                } else {
+-                    const float * k_f32_src = (const float *)k_data;
+-                    for (int64_t dk = 0; dk < DK; dk++) {
+-                        K_f32[dk * KV_TILE_SZ + tk] = k_f32_src[dk];
+-                    }
+-                }
+-            }
++            // K tile (transposed, KV_TILE contiguous) comes from the per-head packed buffer (see above)
++            const float * K_tile = kpack + (ic / KV_TILE_SZ) * DK * KV_TILE_SZ;
+             memset(KQ, 0, Q_TILE_SZ * KV_TILE_SZ * sizeof(float));
+-            simd_gemm(KQ, (const float *)Q_q, K_f32, Q_TILE_SZ, DK, KV_TILE_SZ);
++            simd_gemm(KQ, (const float *)Q_q, K_tile, Q_TILE_SZ, DK, KV_TILE_SZ);
+             ggml_vec_scale_f32(Q_TILE_SZ * KV_TILE_SZ, KQ, scale);
+ 
+             if (logit_softcap != 0.0f) {

stages/stage_p1_pipe/README.md

@@ -0,0 +1,50 @@
+# Stage P1 — pipeline overhead (sampling, non-matmul ops)
+
+Order of work: this stage first, as requested (pipeline before VAE).
+
+## 1. Diagnosis (`GGML_CPU_PROFILE=2`, shape-level MUL_MAT profile, 2 steps, llamafile build)
+
+Per-step numbers (2-step run divided by 2):
+
+| part | per step | notes |
+|---|---|---|
+| main-layer matmuls (M=1088, AMX) | ~3.25 s | w13 48.6 ms, qkv 25.7 ms, w2 24.5 ms, out 9.3 ms per call |
+| noise-refiner matmuls (M=1024, AMX) | ~0.33 s | w13 is 81 ms per call here vs 49 ms for the main layers (unexplained) |
+| `FLASH_ATTN_EXT` | ~0.8 s | F32 tiled kernel |
+| other element-wise ops | ~0.6 s | RMS_NORM+MUL, ADD, SCALE, MUL, CPY, CONT, ROPE |
+
+Finding: the matmul kernel shows **no pipeline overhead** (in-pipeline per-call times match the standalone
+micro-benchmark, `kbench/bench_mm.cpp`). The pipeline overhead is the non-matmul part (~1.4 s/step): mainly flash-attn.
+An earlier attribution of the 1.4 s/step to matmul was wrong; the AMX buffer-name bug in the diagnostic
+(`CPU_AMX` vs `AMX`) is fixed in the uploaded patch.
+
+## 2. Fix P1: flash-attn K packing hoisted to once per head (`patches/ggml-0002-flash-attn-kpack.patch`)
+
+The tiled kernel re-packed K (transposed, KV-tile layout) for every (Q tile, KV tile) pair, i.e. ~17x per head.
+Now each thread packs the whole head once and reuses it for all Q tiles of that head. The cache is reset at each
+chunk call so it never survives a graph execution (scratch buffers are reused and their contents change).
+
+| run (2 steps, same config) | FLASH_ATTN_EXT | sampling |
+|---|---|---|
+| before P1 (`p1 before`, `diag_shape_*`) | 1607.5 ms | 9.89 s |
+| after P1 (`p1_profile_2step.txt`) | 1225.9 ms (-24%) | 9.33 s |
+| after P1, rebuilt from scratch with `build.sh` (`p1_verify_*`) | 1336.2 ms | 11.53 s (host load was high: other tenants at 100% CPU) |
+
+Output: pixel-identical to the pre-P1 build (diff mean 0, max 0), both for the same-tree build and the
+from-scratch `build.sh` build.
+
+Timing caveat: the host is shared (load average ~40). Compare the FLASH_ATTN_EXT profile numbers within a
+batch, not the wall-clock sampling time across batches.
+
+## 3. Build fix found while verifying
+
+`build.sh` now resets local changes inside the ggml submodule before applying patches. Without this, a
+second run on the same work dir failed with "patch does not apply" (`git submodule update` does not revert a
+submodule whose commit did not change).
+
+## Not done yet (next steps of stage P1)
+
+- V tile copy and softmax are still per (Q tile, KV tile); hoisting V packing is the next small step.
+- The F32 tiled kernel reaches only ~0.5 TFLOPS on this machine; a bf16 AMX attention would be the larger change.
+- Element-wise fusion (modulate `x + x*scale`, gated residuals) — candidate for the next step of P1.
+- Noise-refiner w13 is ~1.7x slower per call than the main-layer w13 at the same shape; not explained yet.

stages/stage_p1_pipe/diag_shape_profile_2step.txt

@@ -0,0 +1,46 @@
+PROFMM K N M buf contig calls total_ms per_call_ms
+PROFMM 2560 4096 40 default 1 35 69.5 1.986
+PROFMM 2560 1024 40 default 1 70 127.5 1.821
+PROFMM 4096 2560 40 default 1 35 62.7 1.791
+PROFMM 2560 9728 40 default 1 70 168.6 2.409
+PROFMM 9728 2560 40 default 1 35 92.4 2.639
+PROFMM 2560 3840 40 default 1 2 9.7 4.846
+PROFMM 3840 11520 64 AMX 1 4 6.9 1.736
+PROFMM 3840 3840 64 AMX 1 4 2.6 0.656
+PROFMM 3840 20480 64 AMX 1 4 19.0 4.761
+PROFMM 10240 3840 64 AMX 1 4 6.0 1.512
+PROFMM 64 3840 1024 default 1 2 10.3 5.139
+PROFMM 256 1024 1 default 1 2 0.0 0.013
+PROFMM 1024 256 1 default 1 2 0.0 0.011
+PROFMM 256 15360 1 AMX 1 64 19.0 0.297
+PROFMM 3840 11520 1024 AMX 1 4 108.3 27.070
+PROFMM 3840 3840 1024 AMX 1 4 35.6 8.903
+PROFMM 3840 20480 1024 AMX 1 4 324.4 81.093
+PROFMM 10240 3840 1024 AMX 1 4 96.9 24.232
+PROFMM 3840 11520 1088 AMX 1 60 1539.3 25.656
+PROFMM 3840 3840 1088 AMX 1 60 558.0 9.300
+PROFMM 3840 20480 1088 AMX 1 60 2918.1 48.636
+PROFMM 10240 3840 1088 AMX 1 60 1470.4 24.506
+PROFMM 256 3840 1 default 1 2 0.1 0.043
+PROFMM 3840 64 1088 default 1 2 1.6 0.789
+PROF ADD                    n=     496  total_ms=       199.2  pct=  1.36
+PROF MUL                    n=     323  total_ms=       137.2  pct=  0.93
+PROF REPEAT                 n=       2  total_ms=         0.1  pct=  0.00
+PROF CONCAT                 n=       4  total_ms=         8.2  pct=  0.06
+PROF NORM                   n=       2  total_ms=         1.1  pct=  0.01
+PROF GROUP_NORM             n=      30  total_ms=        65.7  pct=  0.45
+PROF MUL_MAT                n=     593  total_ms=      7646.9  pct= 52.06
+PROF SCALE                  n=     480  total_ms=       137.2  pct=  0.93
+PROF CPY                    n=     243  total_ms=       115.0  pct=  0.78
+PROF CONT                   n=     418  total_ms=       101.8  pct=  0.69
+PROF GET_ROWS               n=       1  total_ms=         5.7  pct=  0.04
+PROF ROPE                   n=      70  total_ms=        64.2  pct=  0.44
+PROF CONV_2D                n=      39  total_ms=      3960.7  pct= 26.96
+PROF UPSCALE                n=       3  total_ms=        28.9  pct=  0.20
+PROF TIMESTEP_EMBEDDING     n=       2  total_ms=         0.0  pct=  0.00
+PROF FLASH_ATTN_EXT         n=     104  total_ms=      1607.5  pct= 10.94
+PROF UNARY                  n=     196  total_ms=        66.8  pct=  0.45
+PROF GLU                    n=      68  total_ms=        78.0  pct=  0.53
+PROF ROPE_APPLY             n=     136  total_ms=        86.9  pct=  0.59
+PROF FUSED_RMS_NORM_MUL     n=     550  total_ms=       378.0  pct=  2.57
+PROF TOTAL_ms=14688.9

stages/stage_p1_pipe/diag_shape_run.log

@@ -0,0 +1,42 @@
+[I] loading diffusion model from 'models/z_image_turbo-Q4_K-ffn13.gguf' --- diffusion_engine.cpp:692
+[I] load models/z_image_turbo-Q4_K-ffn13.gguf using gguf format --- model_loader.cpp:216
+[I] loading llm from 'models/Qwen3-4B-Instruct-2507-Q4_K_M.gguf' --- diffusion_engine.cpp:749
+[I] load models/Qwen3-4B-Instruct-2507-Q4_K_M.gguf using gguf format --- model_loader.cpp:216
+[I] loading vae from 'models/ae.safetensors' --- diffusion_engine.cpp:763
+[I] load models/ae.safetensors using safetensors format --- model_loader.cpp:222
+[I] Version: Z-Image  --- diffusion_engine.cpp:975
+[W] auto-fit: no GPU devices; using the default backend --- backend_fit.cpp:444
+[I] Weight type stat:                      f32: 640  |    q8_0: 18   |    q4_K: 366  |    q6_K: 37    --- diffusion_engine.cpp:1548
+[I] Conditioner weight type stat:          f32: 145  |    q4_K: 216  |    q6_K: 37    --- diffusion_engine.cpp:1549
+[I] Diffusion model weight type stat:      f32: 251  |    q8_0: 18   |    q4_K: 150   --- diffusion_engine.cpp:1550
+[I] VAE weight type stat:                  f32: 244   --- diffusion_engine.cpp:1551
+[I] using VAE for encoding / decoding --- model_builders.cpp:210
+[I] vae decoder: ch = 128 --- auto_encoder_kl.hpp:529
+[I] flash attention auto: CPU -> on (CPU) --- flash_attn.cpp:66
+[I] conv2d direct auto: CPU -> off (no implicit GEMM path) --- conv_direct.cpp:90
+[I] conv3d direct auto: CPU -> off (no implicit GEMM path) --- conv_direct.cpp:90
+[I] total params memory size = 6221.12MB (VRAM 0.00MB, RAM 6221.12MB): text_encoders 2375.91MB(RAM), diffusion_model 3685.21MB(RAM), vae 160.00MB(RAM), controlnet 0.00MB(N/A), extensions 0.00MB(N/A) --- diffusion_engine.cpp:1423
+[I] running in FLOW mode --- diffusion_engine.cpp:1478
+[I] generate_image 512x512 --- image.cpp:869
+[I] get_sigmas with Simple scheduler --- denoiser.hpp:1157
+[I] sampling using Euler method --- request.cpp:477
+[I] qwen3 build cached graph cut plan done (taking 2 ms) --- ggml_graph_cut.cpp:1032
+
  |###                                               |  21/386 -   7.81MB/s
  |##################################################| 386/386 -  10.61GB/s
+[I] loading tensors completed, taking 0.21s (read: 0.12s, memcpy: 0.00s, convert: 0.00s, copy_to_backend: 0.00s) --- model_loader.cpp:1407
+[I] get_learned_condition completed, taking 1.22s --- image.cpp:580
+[I] generating image: 1/1 - seed 42 --- image.cpp:920
+[I] z_image build cached graph cut plan done (taking 2 ms) --- ggml_graph_cut.cpp:1032
+
  |#####                                             |  36/418 - 247.31MB/s
  |###########################                       | 224/418 -   7.89GB/s
  |##################################################| 418/418 -   8.16GB/s
+[I] loading tensors completed, taking 0.44s (read: 0.04s, memcpy: 0.00s, convert: 0.00s, copy_to_backend: 0.31s) --- model_loader.cpp:1407
+
  |=========================>                        | 1/2 -   5.45s/it
  |==================================================| 2/2 -   4.43s/it
+[I] sampling completed, taking 9.89s --- image.cpp:953
+[I] generating 1 latent images completed, taking 9.89s --- image.cpp:965
+[I] decoding 1 latents --- image.cpp:605
+[I] vae build cached graph cut plan done (taking 0 ms) --- ggml_graph_cut.cpp:1032
+
  |####################                              |  55/138 - 465.83MB/s
  |##################################################| 138/138 - 940.30MB/s
+[I] loading tensors completed, taking 0.20s (read: 0.00s, memcpy: 0.00s, convert: 0.01s, copy_to_backend: 0.00s) --- model_loader.cpp:1407
+[I] latent 1 decoded, taking 4.55s --- image.cpp:671
+[I] decode_first_stage completed, taking 4.55s --- image.cpp:675
+[I] generate_image completed in 15.67s --- image.cpp:1140
+[I] save result image 0 to 'pipe_diag/out.png' (success) --- main.cpp:495
+[I] 1/1 images saved --- main.cpp:571

stages/stage_p1_pipe/p1_profile_2step.txt

@@ -0,0 +1,21 @@
+PROF ADD                    n=     496  total_ms=       195.2  pct=  1.41
+PROF MUL                    n=     323  total_ms=        98.6  pct=  0.71
+PROF REPEAT                 n=       2  total_ms=         0.1  pct=  0.00
+PROF CONCAT                 n=       4  total_ms=         7.1  pct=  0.05
+PROF NORM                   n=       2  total_ms=         1.1  pct=  0.01
+PROF GROUP_NORM             n=      30  total_ms=        82.2  pct=  0.59
+PROF MUL_MAT                n=     593  total_ms=      7185.6  pct= 51.72
+PROF SCALE                  n=     480  total_ms=        99.2  pct=  0.71
+PROF CPY                    n=     243  total_ms=        30.2  pct=  0.22
+PROF CONT                   n=     418  total_ms=        49.2  pct=  0.35
+PROF GET_ROWS               n=       1  total_ms=         4.2  pct=  0.03
+PROF ROPE                   n=      70  total_ms=         9.5  pct=  0.07
+PROF CONV_2D                n=      39  total_ms=      4481.8  pct= 32.26
+PROF UPSCALE                n=       3  total_ms=        15.9  pct=  0.11
+PROF TIMESTEP_EMBEDDING     n=       2  total_ms=         0.0  pct=  0.00
+PROF FLASH_ATTN_EXT         n=     104  total_ms=      1225.9  pct=  8.82
+PROF UNARY                  n=     196  total_ms=        27.7  pct=  0.20
+PROF GLU                    n=      68  total_ms=        57.3  pct=  0.41
+PROF ROPE_APPLY             n=     136  total_ms=        70.3  pct=  0.51
+PROF FUSED_RMS_NORM_MUL     n=     550  total_ms=       252.4  pct=  1.82
+PROF TOTAL_ms=13893.4

stages/stage_p1_pipe/p1_run.log

@@ -0,0 +1,42 @@
+[I] loading diffusion model from 'models/z_image_turbo-Q4_K-ffn13.gguf' --- diffusion_engine.cpp:692
+[I] load models/z_image_turbo-Q4_K-ffn13.gguf using gguf format --- model_loader.cpp:216
+[I] loading llm from 'models/Qwen3-4B-Instruct-2507-Q4_K_M.gguf' --- diffusion_engine.cpp:749
+[I] load models/Qwen3-4B-Instruct-2507-Q4_K_M.gguf using gguf format --- model_loader.cpp:216
+[I] loading vae from 'models/ae.safetensors' --- diffusion_engine.cpp:763
+[I] load models/ae.safetensors using safetensors format --- model_loader.cpp:222
+[I] Version: Z-Image  --- diffusion_engine.cpp:975
+[W] auto-fit: no GPU devices; using the default backend --- backend_fit.cpp:444
+[I] Weight type stat:                      f32: 640  |    q8_0: 18   |    q4_K: 366  |    q6_K: 37    --- diffusion_engine.cpp:1548
+[I] Conditioner weight type stat:          f32: 145  |    q4_K: 216  |    q6_K: 37    --- diffusion_engine.cpp:1549
+[I] Diffusion model weight type stat:      f32: 251  |    q8_0: 18   |    q4_K: 150   --- diffusion_engine.cpp:1550
+[I] VAE weight type stat:                  f32: 244   --- diffusion_engine.cpp:1551
+[I] using VAE for encoding / decoding --- model_builders.cpp:210
+[I] vae decoder: ch = 128 --- auto_encoder_kl.hpp:529
+[I] flash attention auto: CPU -> on (CPU) --- flash_attn.cpp:66
+[I] conv2d direct auto: CPU -> off (no implicit GEMM path) --- conv_direct.cpp:90
+[I] conv3d direct auto: CPU -> off (no implicit GEMM path) --- conv_direct.cpp:90
+[I] total params memory size = 6221.12MB (VRAM 0.00MB, RAM 6221.12MB): text_encoders 2375.91MB(RAM), diffusion_model 3685.21MB(RAM), vae 160.00MB(RAM), controlnet 0.00MB(N/A), extensions 0.00MB(N/A) --- diffusion_engine.cpp:1423
+[I] running in FLOW mode --- diffusion_engine.cpp:1478
+[I] generate_image 512x512 --- image.cpp:869
+[I] get_sigmas with Simple scheduler --- denoiser.hpp:1157
+[I] sampling using Euler method --- request.cpp:477
+[I] qwen3 build cached graph cut plan done (taking 2 ms) --- ggml_graph_cut.cpp:1032
+
  |###                                               |  20/386 -  15.62MB/s
  |##################################################| 386/386 -   9.66GB/s
+[I] loading tensors completed, taking 0.23s (read: 0.13s, memcpy: 0.00s, convert: 0.00s, copy_to_backend: 0.00s) --- model_loader.cpp:1407
+[I] get_learned_condition completed, taking 0.49s --- image.cpp:580
+[I] generating image: 1/1 - seed 42 --- image.cpp:920
+[I] z_image build cached graph cut plan done (taking 2 ms) --- ggml_graph_cut.cpp:1032
+
  |#####                                             |  37/418 - 130.98MB/s
  |##########################                        | 210/418 -   7.32GB/s
  |##################################################| 418/418 -   7.87GB/s
+[I] loading tensors completed, taking 0.46s (read: 0.04s, memcpy: 0.00s, convert: 0.00s, copy_to_backend: 0.31s) --- model_loader.cpp:1407
+
  |=========================>                        | 1/2 -   4.79s/it
  |==================================================| 2/2 -   4.53s/it
+[I] sampling completed, taking 9.33s --- image.cpp:953
+[I] generating 1 latent images completed, taking 9.34s --- image.cpp:965
+[I] decoding 1 latents --- image.cpp:605
+[I] vae build cached graph cut plan done (taking 0 ms) --- ggml_graph_cut.cpp:1032
+
  |####################                              |  54/138 - 465.83MB/s
  |##################################################| 138/138 - 935.65MB/s
+[I] loading tensors completed, taking 0.20s (read: 0.00s, memcpy: 0.00s, convert: 0.01s, copy_to_backend: 0.00s) --- model_loader.cpp:1407
+[I] latent 1 decoded, taking 5.07s --- image.cpp:671
+[I] decode_first_stage completed, taking 5.07s --- image.cpp:675
+[I] generate_image completed in 14.89s --- image.cpp:1140
+[I] save result image 0 to 'pipe_p1/out.png' (success) --- main.cpp:495
+[I] 1/1 images saved --- main.cpp:571

stages/stage_p1_pipe/p1_verify_profile_2step.txt

@@ -0,0 +1,21 @@
+PROF ADD                    n=     496  total_ms=       215.4  pct=  1.33
+PROF MUL                    n=     323  total_ms=       155.4  pct=  0.96
+PROF REPEAT                 n=       2  total_ms=         0.1  pct=  0.00
+PROF CONCAT                 n=       4  total_ms=         7.2  pct=  0.04
+PROF NORM                   n=       2  total_ms=         1.2  pct=  0.01
+PROF GROUP_NORM             n=      30  total_ms=        88.4  pct=  0.55
+PROF MUL_MAT                n=     593  total_ms=      8765.4  pct= 54.04
+PROF SCALE                  n=     480  total_ms=       223.9  pct=  1.38
+PROF CPY                    n=     243  total_ms=        68.0  pct=  0.42
+PROF CONT                   n=     418  total_ms=        89.7  pct=  0.55
+PROF GET_ROWS               n=       1  total_ms=         0.1  pct=  0.00
+PROF ROPE                   n=      70  total_ms=         0.8  pct=  0.01
+PROF CONV_2D                n=      39  total_ms=      4632.0  pct= 28.56
+PROF UPSCALE                n=       3  total_ms=        14.6  pct=  0.09
+PROF TIMESTEP_EMBEDDING     n=       2  total_ms=         0.0  pct=  0.00
+PROF FLASH_ATTN_EXT         n=     104  total_ms=      1336.2  pct=  8.24
+PROF UNARY                  n=     196  total_ms=        42.9  pct=  0.26
+PROF GLU                    n=      68  total_ms=        81.3  pct=  0.50
+PROF ROPE_APPLY             n=     136  total_ms=       138.0  pct=  0.85
+PROF FUSED_RMS_NORM_MUL     n=     550  total_ms=       359.3  pct=  2.22
+PROF TOTAL_ms=16219.9

stages/stage_p1_pipe/p1_verify_run.log

@@ -0,0 +1,42 @@
+[I] loading diffusion model from 'models/z_image_turbo-Q4_K-ffn13.gguf' --- diffusion_engine.cpp:692
+[I] load models/z_image_turbo-Q4_K-ffn13.gguf using gguf format --- model_loader.cpp:216
+[I] loading llm from 'models/Qwen3-4B-Instruct-2507-Q4_K_M.gguf' --- diffusion_engine.cpp:749
+[I] load models/Qwen3-4B-Instruct-2507-Q4_K_M.gguf using gguf format --- model_loader.cpp:216
+[I] loading vae from 'models/ae.safetensors' --- diffusion_engine.cpp:763
+[I] load models/ae.safetensors using safetensors format --- model_loader.cpp:222
+[I] Version: Z-Image  --- diffusion_engine.cpp:975
+[W] auto-fit: no GPU devices; using the default backend --- backend_fit.cpp:444
+[I] Weight type stat:                      f32: 640  |    q8_0: 18   |    q4_K: 366  |    q6_K: 37    --- diffusion_engine.cpp:1548
+[I] Conditioner weight type stat:          f32: 145  |    q4_K: 216  |    q6_K: 37    --- diffusion_engine.cpp:1549
+[I] Diffusion model weight type stat:      f32: 251  |    q8_0: 18   |    q4_K: 150   --- diffusion_engine.cpp:1550
+[I] VAE weight type stat:                  f32: 244   --- diffusion_engine.cpp:1551
+[I] using VAE for encoding / decoding --- model_builders.cpp:210
+[I] vae decoder: ch = 128 --- auto_encoder_kl.hpp:529
+[I] flash attention auto: CPU -> on (CPU) --- flash_attn.cpp:66
+[I] conv2d direct auto: CPU -> off (no implicit GEMM path) --- conv_direct.cpp:90
+[I] conv3d direct auto: CPU -> off (no implicit GEMM path) --- conv_direct.cpp:90
+[I] total params memory size = 6221.12MB (VRAM 0.00MB, RAM 6221.12MB): text_encoders 2375.91MB(RAM), diffusion_model 3685.21MB(RAM), vae 160.00MB(RAM), controlnet 0.00MB(N/A), extensions 0.00MB(N/A) --- diffusion_engine.cpp:1423
+[I] running in FLOW mode --- diffusion_engine.cpp:1478
+[I] generate_image 512x512 --- image.cpp:869
+[I] get_sigmas with Simple scheduler --- denoiser.hpp:1157
+[I] sampling using Euler method --- request.cpp:477
+[I] qwen3 build cached graph cut plan done (taking 1 ms) --- ggml_graph_cut.cpp:1032
+
  |###                                               |  22/386 -  31.25MB/s
  |##################################################| 386/386 -  10.23GB/s
+[I] loading tensors completed, taking 0.22s (read: 0.13s, memcpy: 0.00s, convert: 0.00s, copy_to_backend: 0.00s) --- model_loader.cpp:1407
+[I] get_learned_condition completed, taking 0.41s --- image.cpp:580
+[I] generating image: 1/1 - seed 42 --- image.cpp:920
+[I] z_image build cached graph cut plan done (taking 2 ms) --- ggml_graph_cut.cpp:1032
+
  |#####                                             |  37/418 - 261.96MB/s
  |########################                          | 198/418 -   6.75GB/s
  |##################################################| 418/418 -   8.03GB/s
+[I] loading tensors completed, taking 0.45s (read: 0.05s, memcpy: 0.00s, convert: 0.00s, copy_to_backend: 0.30s) --- model_loader.cpp:1407
+
  |=========================>                        | 1/2 -   6.01s/it
  |==================================================| 2/2 -   5.51s/it
+[I] sampling completed, taking 11.53s --- image.cpp:953
+[I] generating 1 latent images completed, taking 11.53s --- image.cpp:965
+[I] decoding 1 latents --- image.cpp:605
+[I] vae build cached graph cut plan done (taking 0 ms) --- ggml_graph_cut.cpp:1032
+
  |###################                               |  52/138 - 340.34MB/s
  |##################################################| 138/138 - 940.30MB/s
+[I] loading tensors completed, taking 0.20s (read: 0.00s, memcpy: 0.00s, convert: 0.01s, copy_to_backend: 0.00s) --- model_loader.cpp:1407
+[I] latent 1 decoded, taking 5.25s --- image.cpp:671
+[I] decode_first_stage completed, taking 5.25s --- image.cpp:675
+[I] generate_image completed in 17.20s --- image.cpp:1140
+[I] save result image 0 to 'pipe_p1_verify/out.png' (success) --- main.cpp:495
+[I] 1/1 images saved --- main.cpp:571