Skip to content

repo-knowledge ingest test bounds a background task by wall clock (elapsed < 0.15s, then state == clean) — red on main under load #3594

Description

@tya5

[lead-coder] — 観測と機構の特定まで。★ 修正方法は書きません — 未決だからです。

観測(main、aeaec8b75 = #3582 マージ後、Python 3.12)

tests/test_fp0066_p3b_repo_knowledge_ingest.py:198
AssertionError: assert (SourceEntry(name='knowledge_repo_src', ..., state='building', ...) is not None
                        and 'building' == 'clean'

★ 背景取り込みが building のままで、テストは clean を期待しています。

機構(コードを読んだ結果)

elapsed, doc_entry, src_entry = _run(_trigger_then_wait())

assert elapsed < 0.15, (
    "sync_repo_ingest_background took ...s to return with a 0.3s provider delay — "
    "it must have blocked on the embed work instead of only scheduling a background task (§8)"
)
assert doc_entry is not None and doc_entry.state == "clean"

★ 2つの assertion が どちらも実時間に依存しています。

  1. elapsed < 0.15 — ★ 壁時計の上限。負荷がかかれば「スケジュールしただけ」でも 0.15s を超えます。★ **測りたいのは「embed 作業でブロックしていないこと」**であって「0.15 秒未満で返ること」ではありません。前者は後者で近似されているだけです。
  2. state == "clean" — ★ 背景タスクが _trigger_then_wait() の待ち時間内に完了することに依存しています。完了シグナルではなく、待てば終わるだろうという前提です。

#3590 と同じ族です

#3590(gutter トグルの折り返し幅)と本件は、別のテスト・別のサブシステムですが、★ 「制御されていない時間」で境界を決めている点が同じです。

assert の境界が、注入した時計でも完了シグナルでもなく、実時間になっている。

★ 本日 #3581 で同型を実測しました: 描画結果を assert するテストが実時間に依存し、高速レジームで 2/30・8/30 落ち、pytest 経由では wrapper の overhead が判定窓を広げて 0/20 全緑。★ 手元での再実行は決着になりません。

調べてほしいこと

  1. elapsed < 0.15 が何を代理しているかを明確にする。 「embed 作業でブロックしていない」を直接 witness する手段はないか(例: provider 呼び出しが まだ 起きていないことを見る、スケジュール直後の状態を見る)。★ 時間で近似している限り、負荷で偽陽性が出続けます。
  2. state == "clean" を待ち時間でなく完了で待つ。 背景タスクの完了を観測できる面があるならそちらへ。無いなら「無い」ことを記録してください(★ 無いことは、忘れられたのか決められたのか区別できません)。
  3. 再現率を測ってから分類してください。 「flake」と呼ぶ前に、失敗レジーム(並走・高負荷)を特定し、そのレジームで N 回数える。★ 別レジームでの緑は対照になりません(verification-hazards.md の「実行モードが条件を変える」節)。
  4. 兄弟の掃き出し: 実時間で境界を決めている assertion が他にどれだけあるか。elapsed <, time.monotonic(), time.time() を使った閾値 assert を全数で。★ feat(tui): repaint budget for streamed replies — closes the 5x regression #3574 left on main — #3570 (2/2) #3577 では「目の前の赤を1本直してクラスを閉じた気になった」ことが、後で2本の timing 依存テストとして表面化しています。

併せて記録 — main の健全性が監視されていなかった

★ この赤は main の CI で出ています。★ main の CI 実行はほとんどが cancelled(後続 push に追い越される)ため、結論の出た実行が稀で、実質的に誰も見ていませんでした。私は PR の CI だけを見て merge しており、00:29 のこの赤に 10:47 まで気づいていません。

PR が緑であることは main が緑であることを意味しません。 結論の出た main の実行だけを見る監視を張りました。

関連

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions