opencoti-llamafile / docs /evaluations /bug858-a4b-drafter-style-divergence.md
ManniX-ITA's picture
Upload folder using huggingface_hub
5ef4cc5 verified
|
Raw
History Blame
15.2 kB

bug-858 A4B β€” drafter accept divergence on long_code_review (side-by-side)

Question: why does the gemma4-assistant drafter accept 0.90 of upstream (b9859) llama.cpp's tokens but only 0.26 of ours (llamafile) on this one prompt β€” while the two are at parity on the other 8 bench prompts?

Setup (identical on both sides)

  • Target: google_gemma-4-26B-A4B-it-Q4_K_M.gguf (sha e718536f) β€” same file, both engines
  • Drafter: gemma-4-26B-A4B-it-assistant.Q8_0.gguf (sha 5963a2ed) β€” same file
  • Greedy (--temp 0), --parallel 1, ctx 4096, RTX 6000 Blackwell (bs2)
  • Below: each engine's own no-spec thinking output for long_code_review, 640 tokens. (The drafter's job is to predict THIS stream token-by-token; that's what the accept-rate measures.)

Per-prompt accept (the gap is ONE prompt)

prompt ours b9859
code_python 0.87 0.92
code_cpp 0.90 0.90
explain_concept 0.77 0.81
summarize 0.92 0.92
qa_factual 0.83 0.92
translation 0.87 0.97
creative_short 0.785 0.7685
stepwise_math 0.91 0.89
long_code_review 0.2583 0.90
aggregate 0.7626 0.8866

Where it forks: a 0.01-logprob coin-flip on a newline (teacher-forced, pos 0-2)

pos 0:  ours '<|channel>'  == b9859 '<|channel>'    (identical, logprob 0.0)
pos 1:  ours 'thought'     == b9859 'thought'       (identical)
pos 2:  ours '\n'   logprob -0.69  (with '\n\n' 2nd at -0.70)   <- picks single newline
        b9859 '\n\n' logprob -0.67  (with '\n'  2nd at -0.71)   <- picks double newline

The two engines' logits agree to 0.01 logprob; they just land on opposite sides of a genuine ~50/50 tie. \n -> ours continues in prose; \n\n -> b9859 continues in bullets. That single newline is the entire cause of the style split below.

================================================================================ ## OURS (llamafile) β€” drafter accept 0.26

Python FastAPI, Postgres 15, 4 replicas, Nginx LB. Read user $\to$ Fetch 50 events (partitioned table) $\to$ Compute score $\to$ Update user $\to$ Insert history $\to$ Cache. p50 = 35ms, p99 = 1.8s (periodic, every ~90s). Elevated Postgres CPU during spikes. No correlation with connection count. 20 per replica (80 total). PgBouncer (transaction mode) pool size 50. users (50M), events (2B, partitioned by month, index on (user_id, ts DESC)), score_history (800M, index on user_id). Autovacuum at default. Nightly batch job (not the cause). PgBouncer waiting connections (8-12) during spikes. App CPU low. Network RTT low (0.4ms).

*   *The Transaction Block:* `async with db.transaction() as tx:` wraps everything.
    *   `SELECT ... FOR UPDATE`: This locks the user row.
    *   `SELECT ... FROM events`: This is a read.
    *   `UPDATE users`: This is a write.
    *   `INSERT INTO score_history`: This is a write.
*   *The Lock Duration:* The lock on the `users` row is held from the first `SELECT FOR UPDATE` until the end of the `async with` block.
*   *The "90-second" pattern:* This is a huge clue. Periodic spikes often suggest:
    *   Autovacuum/Maintenance tasks.
    *   Periodic background jobs.
    *   *Wait, what about the `score_history` table?* It's 800M rows.
    *   *What about the `events` table?* 2B rows, partitioned.
*   *The Postgres CPU spike:* High CPU without high connection count suggests heavy computation, index scans, or contention/locking overhead.
*   *The PgBouncer waiting connections:* This means the application is waiting for a connection from the pool. Since the app CPU is low, the app is blocked on I/O or waiting for a DB connection.

*   *Hypothesis 1: Lock Contention / Row Contention.*
    If multiple requests for the *same* `user_id` come in, they will queue on the `FOR UPDATE` lock. However, the prompt says "intermittent latency spikes" and "elevated Postgres CPU." Lock contention usually *lowers* CPU (processes are sleeping/waiting). High CPU suggests active work.

*   *Hypothesis 2: Autovacuum / Bloat / Index Maintenance.*
    The `score_history` table is 800M rows. Every request does an `INSERT`. This generates a lot of dead tuples

================================================================================ ## B9859 (upstream llama.cpp) β€” drafter accept 0.90

  • Service: Python FastAPI (4 replicas).
  • Database: Postgres 15.
  • Load Balancer: Nginx.
  • Connection Management: PgBouncer (Transaction mode, pool size 50).
  • App Connection Pool: 20 per replica (Total 80).
  • Workflow:
    1. SELECT ... FOR UPDATE on users (locks the row).
    2. SELECT from events (partitioned, 2B rows, index on (user_id, ts DESC)).
    3. Compute score (CPU in app).
    4. UPDATE users.
    5. INSERT INTO score_history (800M rows, index on user_id).
    6. cache.set (Redis/Memcached).
  • Performance:
    • p50: 35ms.
    • p99: 1.8s (every 90s, regular pattern).
    • Correlation: High Postgres CPU, but not high connection count.
    • PgBouncer: Occasional waiting connections (8-12).
    • App CPU: Low (<30%).
    • Network RTT: Low (0.4ms).
  • Schema:
    • users: 50M rows.

    • events: 2B rows, partitioned by month, index (user_id, ts DESC).

    • score_history: 800M rows, index user_id.

    • Autovacuum: Default.

    • Hypothesis 1: Lock Contention / Row Locking. The code uses SELECT ... FOR UPDATE. If the same user_id is hit frequently, requests will queue. However, the spikes are "regular" (every 90s) and affect Postgres CPU. Lock contention usually increases latency but doesn't necessarily spike CPU unless there's a massive amount of retries or context switching. But wait, if many requests are waiting for the same lock, they aren't consuming CPU; they are idle.

    • Hypothesis 2: Index/Table Bloat and Autovacuum. score_history is 800M rows and unpartitioned. Every request does an INSERT. This causes massive bloat. users is also updated. If autovacuum kicks in or if the index on score_history becomes extremely fragmented/large, it could cause spikes. But autovacuum is usually a background process. However, a "regular pattern" every 90 seconds suggests something periodic.

    • Hypothesis 3: Transaction Duration and Lock Holding. The transaction wraps the compute_score function. If compute_score is slow or if the `events

================================================================================

Verdict

Both continuations are coherent, competent code reviews (lock contention, autovacuum/bloat, the 90-second pattern β€” both get there). Ours is NOT degenerate. The only difference is FORMATTING: ours opens with a terse LaTeX-arrow summary ($\to$, $p50=35\text{ms}$) then settles into nested bullets; b9859 uses clean bullets from the first line. The distilled gemma4-assistant drafter predicts the standard bullet stream far better than ours' LaTeX-heavy prose stream β€” so it accepts 0.90 of b9859 and 0.26 of ours. The target itself is at parity (logits match upstream to 0.01 logprob); the accept gap is the drafter being style-sensitive, triggered by an unfixable floating-point newline coin-flip. Not a target bug, not degeneration.

================================================================================ ## FOLLOW-UP: is the LaTeX ours' degeneration? (teacher-forced, token-level)

Hypothesis (well-reasoned): nothing in the prompt cues LaTeX; nobody opens a reasoning trace with $\to$ / $\text{ms}$. If the drafter (distilled from true A4B) and upstream both avoid it, then ours emitting it = ours drifting off-distribution = degeneration.

Test: teacher-force ours' EXACT 24-token prefix into BOTH engines (/apply-template + /v1/completions logprobs) and read each engine's logprob for OURS' own next token. If ours is degenerate, upstream (the reference) will rank ours' LaTeX token low and greedily prefer a plain word/arrow. sane=Y means ours' greedy reproduced ours' own token (reconstruction valid).

pos | ours_next    |  o_lp | sane |   up_lp | up_greedy    | up_top3
  2 | '\n'         | -0.66 |   Y  |  -0.68  | '\n'         | ['\n' -0.7, '\n\n' -0.7, ')' -13.7]
  3 | 'Python'     | -0.21 |   Y  |  -0.20  | 'Python'     | ['Python' -0.2, 'Fast' -2.2, '*' -3.2]
  6 | ' Postgres'  | -0.09 |   Y  |  -0.06  | ' Postgres'  | [' Postgres' -0.1, ' ' -3.2, ' PostgreSQL' -4.4]
 15 | ' N'         | -0.19 |   Y  |  -0.24  | ' N'         | [' N' -0.2, ' nginx' -1.5, ' ' -8.6]
 20 | 'Read'       | -0.73 |   Y  |  -0.88  | 'Read'       | ['Read' -0.9, '`' -1.0, 'Reads' -2.4]
 21 | ' user'      | -0.04 |   Y  |  -0.03  | ' user'      | [' user' -0.0, ' `' -3.7, ' User' -4.8]
 22 | ' $\'        | -0.48 |   Y  |  -0.55  | ' $\'        | [' $\' -0.5, ',' -1.7, ' ->' -2.1]   <== the LaTeX

(full 0-23 in tf_ours.json / tf_up.json)

RESULT β€” hypothesis REFUTED. At the decisive LaTeX position (k=22), upstream's OWN greedy pick is $\ (the LaTeX), logprob -0.55 vs ours' -0.48 β€” and the plain-arrow -> is upstream's THIRD choice at -2.1, a full 1.6 logprob BELOW the LaTeX. Across all 23 positions ours' and upstream's logprobs for ours' tokens agree to ~0.1 and upstream's greedy == ours' token every time. Upstream avoids LaTeX from-scratch ONLY because the pos-2 newline coin-flip put it on the bullet path (numbered workflow), so the "Read user ->" prose context never arises. Put upstream ON that context and it writes the same LaTeX. => The LaTeX is a real A4B behavior both engines share on the prose path, not ours' degeneration. Ours' A4B decode is at genuine token-level parity with upstream.

================================================================================ ## CORRECTION (decisive): branch-forcing acceptance matrix β€” ours IS degraded

The teacher-forced test above validated the TARGET's output logits β€” but MTP acceptance depends on the DRAFTER (which eats the target's HIDDEN STATE), a path the logit test never touched. Forcing BOTH engines onto BOTH branches (identical prefix tokens, spec server, n1, temp 0) and measuring the drafter's acceptance:

            prose(\n)   bullet(\n\n)
ours          0.1286      0.4766
upstream      0.7753      0.8588

Read the COLUMNS. On the IDENTICAL bullet branch (same forced tokens; both emit near-identical * Service: Python FastAPI (4 replicas)...), ours=0.48 vs upstream=0.86 β€” a 0.38 gap that is NOT the branch. Upstream holds 0.78 even on the prose branch that collapses ours to 0.13. So:

  • the branch / newline coin-flip is NOT the cause;
  • ours' DRAFTER path is genuinely worse on EVERY branch of this prompt;
  • the degeneration is REAL (in the drafter/acceptance path), not a benign tie-break.

The LaTeX turned out to be a red herring for the MECHANISM (upstream-forced-to-prose ALSO emits $\rightarrow$ β€” it IS a real A4B prose-path behavior) β€” but the underlying instinct "ours is degenerate" was CORRECT: it's just in the drafter path, not the target text.

Likely root cause: ours' hidden-state harvest / shared-KV drafter read is LENGTH-DEPENDENT wrong (8/9 short bench prompts are at parity; only long_code_review, ~760-token prefill, degrades). VERDICT REVERSED: #607 is NOT at parity; do NOT ship #608 as "parity achieved" β€” root-cause the ctx_dft drafter degradation at long prefill first.


RESOLUTION 2026-07-04 (identical-forced-prefix token comparison β€” SUPERSEDES the CORRECTION section)

The prior "CORRECTION" claimed ours' drafter is genuinely degraded because a branch-forcing matrix showed ours 0.48 vs upstream 0.86 on the "same" (forced-bullet) branch. That matrix was confounded: forcing only the 3-token prefix, then letting each engine generate freely, does NOT produce the same tokens. Decisive re-test (seqcmp-run.sh/seqcmp-up.sh, identical forced-bullet prefix bf_ids.json[bullet], temp 0, --parallel 1, n1, capturing return_tokens):

ours     accept 0.269   120 toks
upstream accept 0.815   120 toks
shared prefix = 6 tokens, then DIVERGE (ours=236761 "." vs up=568 " (")

Both continuations are COHERENT, non-degenerate bullet workflows β€” they simply diverge at token #6 from a benign per-token numerical coin-flip (ours' CUDA kernels vs upstream's), the same class as the earlier pos-2 \n/\n\n flip and #495 base-numerics:

  • ours (accept 0.27): Service: Python FastAPI. Β· Database: PostgreSQL 15. Β· Deployment: 4 replicas, Nginx LB. Β· Workflow: 1. SELECT … FOR UPDATE on users Β· 2. SELECT … LIMIT 50 on events (partitioned) Β· 3. Compute score Β· 4. UPDATE users Β· 5. INSERT INTO score_history Β· 6. SET cache
  • upstream (accept 0.82): Service: Python FastAPI (4 replicas). Β· Database: Postgres 15 (via PgBouncer in transaction mode). Β· Load Balancer: Nginx. Β· Workflow: 1. Start transaction. Β· 2. SELECT … FOR UPDATE on users Β· 3. SELECT … from events (partitioned, 2B rows, index on …) Β· 4. Compute score (CPU intensive? Not specified …

Ours' continuation is terser and more code/SQL-dense (backticks, table names, FOR UPDATE); upstream's is more discursive natural language. Code/SQL tokens are intrinsically higher-entropy = harder to self-draft than NL boilerplate β€” that is why ours' accept is lower on its own (different) content. The accept metric is measured over DIFFERENT token streams, so it never proved a drafter defect.

Verdict

  • No degeneration. Ours is coherent on BOTH branches. The LaTeX seen from-scratch is a shared A4B behavior on the prose branch (upstream's own greedy picks it too β€” tf test), not ours-specific.
  • Drafter is at parity. 8/9 bench prompts match upstream; the gemma4-assistant drafter runs mechanically correctly (DBG858 dual-ctx dump: posmax dft == tgt every step, real pending_h/ out_h, position tracks frontier; no truncation, no null-harvest).
  • The residual aggregate gap is base-numerics content-divergence on knife-edge thinking prompts (ours' valid-but-denser continuation is harder to self-draft), NOT a ctx_dft port bug. Closing it would require bit-identical base kernels (#495 class) β€” out of scope for the MTP port.
  • Auto-policies ruled out: sparse-V never armed (f16, not quantized-V), rolling-KV FULLY RESIDENT (inert), SWA irrelevant (n_swa=1024 ≫ 760-tok prefill).

Ship note: #607 dual-ctx port is functionally correct and drafter-at-parity β†’ #608 may ship. Do NOT chase the 1/9 aggregate gap as a drafter fix β€” it is the #495 base-numerics rabbit hole. Evidence: /srv/ml/opencoti-c1/bug858-a4b-mtp/seqcmp_{ours,up}.json, dbg858b.server.log (DBG858).