chore: PR #237 회차 2 리뷰 반영 — 모수 정합 + 올림 + 라벨 정정

2회차 리뷰가 1회차 지적 6건 모두 실질 해결을 확인하고(마이크로초 전환에
누락된 누적 지점 없음, 단위 1000배 오차 없음) 머지 가능으로 결론냈다.
남은 셋을 반영한다.

1) HOTFIXES 두 표의 모수가 정확히 2배 어긋났다 (MEDIUM)

   A/B 표는 "문서 792건 / 16,379 청크", 내역 표는 "1,584건 / 32,758" 이었다.
   원인을 추적해 보니 **측정 설정의 artifact** 였다. 시험용 config 를 dogfood
   config 에서 sed 로 만들면서 `[[workspace.sources]]` 두 개(wiki / jira)의
   root 가 같은 디렉토리를 가리키게 됐고, walker 가 파일 1,157개를 두 번
   스캔해 run 하나가 자산 처리 1,584건을 낸다.

   A/B 두 run 이 완전히 같은 설정을 쓰므로 비교 자체는 유효하지만, 이 PR 의
   산출물이 "실측 근거" 이므로 무엇을 몇 건 쟀는지 정확히 적어야 한다.
   코퍼스 / 저장 결과 / run 당 조회 수를 나눠 적고 artifact 를 명시했다.
   상한 2.2초의 유도(0.6 + 1,584 × 1 ms)도 이제 모수와 맞는다.

2) emit 시점 ms 절삭이 계통적 하한으로 남아 있었다 (MEDIUM)

   내부 누적만 마이크로초가 됐고 wire 필드는 여전히 내림이라, 저자 자신의
   데이터대로면 90% 자산이 계속 0 으로 찍힌다. 소비자가 합산하면 자산 수 ×
   최대 1 ms 만큼 계통적으로 과소 계상된다.

   `div_ceil` 로 올림했다. 같은 run 을 다시 재니 0 으로 찍히는 자산이 하나도
   없고 합이 2.1초다 — 내림 0.6초가 하한, 올림 2.1초가 상한이므로 앞서
   산술로 낸 0.6~2.2초 구간이 실측으로 확인됐다.

3) cache_ms 라벨이 blake3 키 해싱을 빠뜨렸다 (MEDIUM)

   `t_cache` 타이머는 `derivation_cache_key` 계산부터 시작한다. 청크 본문
   전체를 해싱하는 순수 CPU 비용이라, "lookup" 만 적힌 라벨은 미스 위주
   run 에서 실제로 오해를 만든다. 구조체 주석·필드 주석·스키마 셋 다 고쳤다.

4) 잔가지 (LOW)

   - `t_decode` 주석이 "디코드" 라고만 해서 실제로는 히트/미스 분류 루프
     전체를 감싼다는 점이 안 드러났다.
   - `CacheStats` 의 hit / miss 필드에만 주석이 없었다.
   - DOGFOOD 의 "warm 재색인이면 cache_miss == 0" 은 `--force-reingest`
     일 때만 성립한다. 그냥 재색인하면 변경 없는 문서가 통째로 skip 되어
     `asset_timings` 자체가 안 나온다.

미반영: `get_many` 의 `prepare_cached` 가 배치 크기마다 SQL 문자열이 달라져
사실상 캐시 미스라는 지적 — 정확하지만 누수도 정확성 문제도 없고, 버킷
패딩은 1% 짜리에 낼 복잡도가 아니다. tracing 로그가 us 라 자릿수가 길다는
점도 단위 표기와 값이 맞으므로 그대로 둔다.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017c9JwQq8ZkGvYjpKXMiDhF

crates/kebab-app/src/ingest.rs

@@ -1018,13 +1018,19 @@ fn unsupported_media_warning(path: &str) -> String {
 /// a cache that looks free.
 #[derive(Default)]
 pub(crate) struct CacheStats {
+    /// Chunks whose embedding was already cached.
     pub hit: usize,
+    /// Chunks whose embedding had to be computed.
     pub miss: usize,
     /// Keys that hit, for the batched `last_used_at` bump the caller runs
     /// after the vector upsert.
     pub touch_keys: Vec<String>,
-    /// Lookup + decode + insert + touch, in **microseconds**. Not the
+    /// Cache-key hashing + lookup + hit/miss split + insert + touch, in
-    /// embedder call the misses trigger.
+    /// **microseconds**. Not the embedder call the misses trigger.
+    ///
+    /// The blake3 key hashing is inside the timer on purpose: it hashes
+    /// every chunk's full text and is pure CPU, so a label that said only
+    /// "lookup" would misattribute it on a miss-heavy run.
     ///
     /// Microseconds because a per-asset millisecond truncation loses the
     /// measurement entirely: a document's cache work is routinely
@@ -1068,8 +1074,8 @@ fn embed_with_cache(
     let mut miss_indices: Vec<usize> = Vec::new();
     let mut miss_inputs: Vec<EmbeddingInput<'_>> = Vec::new();
 
-    // Decoding a hit's payload back into `Vec<f32>` is part of what the
+    // The hit/miss split, including decoding a hit's payload back into
-    // cache costs, so it is inside the timer too — a metric that stopped
+    // `Vec<f32>`, is part of what the cache costs — a metric that stopped
     // at the SQL boundary would flatter the cache.
     let t_decode = std::time::Instant::now();
     for (i, text) in texts.iter().enumerate() {
@@ -1484,7 +1490,7 @@ fn ingest_one_asset(
             caption_ms: 0,
             cache_hit: u32::try_from(emb_cache.hit).unwrap_or(u32::MAX),
             cache_miss: u32::try_from(emb_cache.miss).unwrap_or(u32::MAX),
-            cache_ms: emb_cache.us / 1_000,
+            cache_ms: emb_cache.us.div_ceil(1_000),
         },
     );
 
@@ -1895,7 +1901,7 @@ fn ingest_one_image_asset(
             caption_ms,
             cache_hit: u32::try_from(emb_cache.hit).unwrap_or(u32::MAX),
             cache_miss: u32::try_from(emb_cache.miss).unwrap_or(u32::MAX),
-            cache_ms: emb_cache.us / 1_000,
+            cache_ms: emb_cache.us.div_ceil(1_000),
         },
     );
 
@@ -2789,7 +2795,7 @@ fn ingest_one_pdf_asset(
             caption_ms: 0,
             cache_hit: u32::try_from(emb_cache.hit).unwrap_or(u32::MAX),
             cache_miss: u32::try_from(emb_cache.miss).unwrap_or(u32::MAX),
-            cache_ms: emb_cache.us / 1_000,
+            cache_ms: emb_cache.us.div_ceil(1_000),
         },
     );
 

crates/kebab-app/src/ingest_progress.rs

@@ -154,9 +154,15 @@ pub enum IngestEvent {
         cache_hit: u32,
         #[serde(default)]
         cache_miss: u32,
-        /// Lookup, payload decode, insert, and the `last_used_at` touch
+        /// Cache-key hashing, lookup, payload decode, insert, and the
-        /// that every hit triggers — everything the cache costs except
+        /// `last_used_at` touch that every hit triggers — everything the
-        /// the embedder call the misses go on to make.
+        /// cache costs except the embedder call the misses go on to make.
+        ///
+        /// Rounded **up** to the millisecond. An asset's cache work is
+        /// routinely sub-millisecond, so truncating would report zero for
+        /// most assets and make any sum a systematic undercount; the cost
+        /// of rounding up is at most 1 ms per asset in the other
+        /// direction, which does not hide a cache that is expensive.
         ///
         /// The touch is counted deliberately: issue #231's sharpest claim
         /// is that a read-only cache hit generates write traffic, and a

docs/DOGFOOD.md

@@ -278,7 +278,7 @@ echo "# stdin content" | "$RELEASE_BIN" ingest-stdin --title "from stdin" --conf
 - sweep 이 끝난 뒤 진행바가 asset 분모·라벨로 돌아오는가 (TTY). sweep 이 같은 바를 빌려 쓰므로 복구가 빠지면 색인 구간 내내 `sweep [..] 4213/21` 로 그려진다.
 - ndjson 로그에 `purge` 줄과 `sweep_summary` 가 남는가 (이슈 #228 이전에는 이 구간이 0바이트였다). purge 실패 시 `purge_failed`.
 - sweep 중 Ctrl-C 한 번에 실제로 멈추는가. `sweep_completed.checked` 가 예고한 `total` 이 아니라 실제 검사한 수로 나와야 한다.
-- `asset_timings` 의 `cache_hit` / `cache_miss` / `cache_ms` (v0.32.1, issue #231). warm 재색인이면 `cache_miss == 0` 이어야 한다. `cache_ms` 는 **`embed_ms` 에 포함된** 값이라 phase 를 합산할 때 이중 계상하지 말 것. 임베딩 kind 만 세므로 이미지·PDF 위주 코퍼스에서는 캐시가 한 일을 과소 표현한다. code 자산은 `asset_timings` 자체를 emit 하지 않는다.
+- `asset_timings` 의 `cache_hit` / `cache_miss` / `cache_ms` (v0.32.1, issue #231). `--force-reingest` 로 warm 재색인하면 `cache_miss == 0` 이어야 한다(그냥 재색인하면 변경 없는 문서가 통째로 skip 되어 `asset_timings` 자체가 안 나온다). `cache_ms` 는 **`embed_ms` 에 포함된** 값이라 phase 를 합산할 때 이중 계상하지 말 것. 임베딩 kind 만 세므로 이미지·PDF 위주 코퍼스에서는 캐시가 한 일을 과소 표현한다. code 자산은 `asset_timings` 자체를 emit 하지 않는다.
 
 ---
 

docs/wire-schema/v1/ingest_progress.schema.json

@@ -235,7 +235,7 @@
     "cache_ms": {
       "type": "integer",
       "minimum": 0,
-      "description": "asset_timings: what the derivation-cache path cost — lookup, payload decode, insert, and the last_used_at touch — excluding the embedder call the misses trigger. INCLUDED IN embed_ms rather than additional to it: the embed timer spans the whole vector phase, so summing the phase fields double-counts this one."
+      "description": "asset_timings: what the derivation-cache path cost — cache-key hashing, lookup, payload decode, insert, and the last_used_at touch — excluding the embedder call the misses trigger. Rounded UP to the millisecond, because an asset's cache work is routinely sub-millisecond and truncating would make any sum a systematic undercount. INCLUDED IN embed_ms rather than additional to it: the embed timer spans the whole vector phase, so summing the phase fields double-counts this one."
     }
   }
 }

tasks/HOTFIXES.md

@@ -20,16 +20,25 @@ git history.
 
 #231 은 "캐시가 히트하는데도 캐시를 우회하고 전량 재임베딩하는 편이 더 빠르다" 고 보고하면서, 본문에 **"⚠️ 정량 실측 보완 필요 … 수치 미기록"** 이라고 표를 비워 뒀다. 그 표를 채운 것이 이 항목이다.
 
-측정 환경: 나무위키 문서 792건 / chunk 16,379개, ollama + snowflake-arctic-embed2 (1024-dim), `--force-reingest` 로 전 문서 full re-process. 캐시 우회는 `derivation_cache` 테이블을 비워 전량 미스로 만들었다.
+측정 환경을 먼저 정확히 적는다 — 리뷰에서 두 표의 모수가 어긋난다는 지적을 받아 바로잡은 것이다.
 
-| 조건 | 총 소요 | chunk/초 |
+- 코퍼스: 나무위키 마크다운 **1,157 파일**. 그중 730개는 확장자가 없어 skip 되고, 나머지가 색인된다.
-|---|---|---|
+- **측정 설정의 artifact**: 이 시험용 config 는 `[[workspace.sources]]` 두 개(`wiki` / `jira`)가 **같은 root 를 가리킨다**. dogfood config 를 `sed` 로 고쳐 쓰면서 두 source 의 root 가 같아졌다. 그래서 walker 가 파일을 두 번 스캔하고, run 하나가 **자산 처리 1,584건**을 낸다. A/B 두 run 이 완전히 같은 설정을 쓰므로 비교 자체는 유효하지만, 수치를 읽을 때 알고 있어야 한다.
-| 캐시 히트 경로 | **139.1초** | 236 |
+- 저장된 결과: 문서 792건 / chunk 16,379개 / 캐시 항목 14,599개.
-| 캐시 우회(전량 재임베딩) | **1179.6초** | 28 |
+- run 당 임베딩 캐시 조회 32,758회 (자산 처리 1,584건 × 평균 21청크).
+- 임베더: ollama + snowflake-arctic-embed2 (1024-dim). `--force-reingest` 로 문서 skip 을 우회해 전 문서 재처리.
+- 캐시 우회는 `derivation_cache` 테이블을 비워 전량 미스로 만들었다.
+
+| 조건 | 총 소요 |
+|---|---|
+| 캐시 히트 경로 | **139.1초** |
+| 캐시 우회(전량 재임베딩) | **1179.6초** |
 
 **캐시 히트가 8.5배 빠르다.** 이슈의 가설은 이 환경에서 재현되지 않는다.
 
-새로 넣은 `asset_timings` 계측으로 내역을 뜯어보면 더 분명하다 (문서 1,584건 / 히트 32,758 / 미스 0, run 141.3초):
+배칭 수정 전후(A-before / A-after)는 139.1초 / 139.3초로 측정 오차 안이다.
+
+새로 넣은 `asset_timings` 계측으로 내역을 뜯어보면 더 분명하다. 아래는 계측 정밀도를 고친 뒤의 별도 run(141.3초, 위 A/B 와 같은 스냅샷에서 시작, 자산 처리 1,584건 / 히트 32,758 / 미스 0):
 
 | 구간 | 소요 | 비중 |
 |---|---|---|
@@ -37,15 +46,15 @@ git history.
 | `store_ms` — SQLite 문서·청크 기록 | 57.0초 | 40% |
 | `chunk_ms` | 4.4초 | 3% |
 | `parse_ms` | 0.1초 | 0% |
-| ↳ 그중 **캐시 경로**(키 계산+조회+디코드+삽입+touch) | **0.6~2.2초** | **0.4~1.6%** |
+| ↳ 그중 **캐시 경로**(키 해싱+조회+디코드+삽입+touch) | **0.6~2.2초** | **0.4~1.6%** |
 
-두 가지를 정확히 적어 둔다. 리뷰에서 지적받아 고친 것들이다.
+두 가지를 정확히 적어 둔다. 둘 다 리뷰에서 지적받아 고친 것이다.
 
 `embed_ms` 는 "Lance upsert" 가 아니다. `t_embed` 스팬은 orphan purge(`purge_vector_orphans_for_workspace_path`) + 캐시 경로 + 임베더 호출 + 레코드 구성 + Lance upsert + touch 를 전부 감싼다 — 코드 주석 자신이 "purge + upsert" 라고 적고 있다.
 
-캐시 경로는 **`embed_ms` 안에 포함된 부분집합**이지 별도 가산 항목이 아니다. 그리고 0.6초는 **하한**이다. `cache_ms` 는 문서당 한 번 ms 로 절삭되는데 문서 하나의 캐시 작업이 대개 1 ms 미만이라 **1,584건 중 1,422건(90%)이 0 으로 찍혔다**. 절삭 상한이 문서당 1 ms 이므로 참값은 0.6~2.2초 구간이다. 초안은 이걸 0.6초 점추정으로 적었고, 그 숫자를 근거로 제안 3·6 을 기각했다 — 구간으로 고쳐 적는다. 결론(캐시 경로가 run 의 몇 %)은 구간 어느 쪽에서도 같다.
+캐시 경로는 **`embed_ms` 안에 포함된 부분집합**이지 별도 가산 항목이 아니다. 그리고 0.6초는 **하한**이었다. `cache_ms` 는 자산당 한 번 ms 로 절삭되는데 자산 하나의 캐시 작업이 대개 1 ms 미만이라 **1,584건 중 1,422건(90%)이 0 으로 찍혔다**. 절삭 상한이 자산당 1 ms 이므로 참값은 0.6~2.2초 구간이다. 초안은 이걸 0.6초 점추정으로 적었고 그 숫자를 근거로 제안 3·6 을 기각했다 — 구간으로 고쳐 적는다. 결론(캐시 경로가 run 의 몇 %)은 구간 어느 쪽에서도 같다.
 
-내부 누적은 마이크로초로 바꿔 절삭 지점을 문서당 3곳에서 1곳(emit 시점)으로 줄였고, 히트 payload 를 `Vec<f32>` 로 되돌리는 디코드 비용도 캐시 경로에 계상했다 — SQL 경계에서 멈추는 지표는 캐시를 실제보다 싸 보이게 한다.
+내부 누적을 마이크로초로 바꿔 절삭 지점을 자산당 3곳에서 1곳(emit)으로 줄였고, 그 1곳은 **올림**으로 바꿔 계통적 하한을 없앴다. 올림 후 같은 run 을 다시 재니 0 으로 찍히는 자산이 하나도 없고 합이 **2.1초** 였다 — 내림이 하한 0.6초, 올림이 상한 2.1초이므로 참값은 그 사이이고, 앞서 산술로 낸 0.6~2.2초 구간이 실측으로 확인된 셈이다. 어느 쪽이든 run 141초의 1.5% 이하다. 히트 payload 를 `Vec<f32>` 로 되돌리는 디코드 비용과 blake3 키 해싱도 캐시 경로에 계상했다 — SQL 경계에서 멈추는 지표는 캐시를 실제보다 싸 보이게 한다.
 
 ### 왜 원 보고가 틀렸다고 단정하지 않는가