refactor(app): #231 derivation cache 배칭 + 계측 — 가설은 재현 안 됨 #237
Reference in New Issue
Block a user
Delete Branch "refactor/derivation-cache-batching"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
요약
#231 은 "캐시가 히트하는데도 캐시를 우회하고 전량 재임베딩하는 편이 더 빠르다" 고 보고하면서, 본문에 "⚠️ 정량 실측 보완 필요 … 수치 미기록" 이라고 표를 비워 뒀다. 그 표를 채우는 것이 이 PR 의 핵심이다.
측정 결과 가설이 재현되지 않는다. 나무위키 문서 792건 / chunk 16,379개, ollama + snowflake-arctic-embed2 (1024-dim),
--force-reingest로 전 문서 full re-process. 캐시 우회는derivation_cache테이블을 비워 전량 미스로 만들었다.캐시 히트가 8.5배 빠르다.
이 PR 이 추가한 계측으로 139초의 내역을 뜯어보면 더 분명하다 (히트 32,758 / 미스 0):
이슈가 지목한 여섯 원인이 전부 합쳐서 run 의 0.4% 다.
다만 "보고가 틀렸다" 로 읽으면 안 된다
보고 이후 #229(chunks_fts 삭제가 FTS5 전체 스캔)와 #230(Lance fragment 누적)이 머지됐다. #231 본문 스스로 #229 를 "같은
Mutex<Connection>을 공유하므로 상호 증폭" 이라고 적었다. 원 보고 환경에서는 캐시 조회 52,000회가 전부 그 뮤텍스를 잡았다 놓는데, 같은 뮤텍스 위에서 chunk 삭제가 FTS5 전체 스캔을 돌리고 있었다. "#229 를 먼저 고치면 본 이슈의 체감도 함께 줄어든다" 역시 이슈가 예측한 그대로다.그러니 이 실측은 "#229 가 머지된 뒤에는 재현되지 않는다" 로 읽는 것이 맞다. 이 머신이 61 GB RAM 이라 DB 가 통째로 페이지 캐시에 올라간다는 점도 함께 밝혀 둔다.
이슈를 닫을지 여부는 이 PR 이 결정하지 않는다. 실측을 기록하는 데까지가 이 PR 의 범위다.
반영한 것
제안 1·2·4 는 실측과 무관하게 왕복 수가 줄 뿐 잃는 것이 없어서 넣었다. 다만 A/B 벽시계 차이는 139.1초 → 139.3초로 측정 오차 안 이다. 정직하게 말해 이 코퍼스에서는 체감이 없다.
derivation_cache_get_many—WHERE cache_key IN (…)배치 조회. 문서 하나가 평균 21 chunk 이므로 왕복이 21회에서 1회가 된다. 900개마다 statement 를 나눠 파라미터 상한을 넘지 않는다.derivation_cache_put_many— 미스 벡터를 한 트랜잭션에. 기존 단건put은 명시 트랜잭��� 밖이라 행마다 암묵 커밋이었다.prepare_cached— get / put / touch 셋 다.query_row는 호출마다 SQL 을 다시 파싱한다.제안 5(계측 노출)가 이번의 실질적 산출물이다.
asset_timings에cache_hit/cache_miss/cache_ms를 additive 로 실었다. 이전에는 hit/miss 가tracing::info!로 stderr 에만 나가서 run 이 끝나면 사라졌고, "내 코퍼스에서 캐시가 이득인가" 를 사용자가 확인할 방법이 없었다. TTY 에서는⏱ … embed 75ms · cache 21/21 0ms · store 36ms로 보인다.cache_ms에는 touch 도 포함한다. 이슈의 가장 날카로운 지적이 "읽기 전용이어야 할 히트 경로가 쓰기 트래픽을 만든다" 인데, touch 를 빼고 재는 지표로는 그 주장을 검증할 수 없다.네 out-param 은
CacheStats구조체로 묶었다. 함께 읽히고 함께 보고되는 값들이고, 셋만 갱신하고 하나를 빠뜨리면 캐시가 공짜인 것처럼 보고된다.반영하지 않은 것
created_at기반 TTL)은 LRU 를 age 기반 축출로 바꾸는 의미 변경이다. 근거 없이 할 변경이 아니다.page_size변경은 기존 DB 에서 VACUUM 을 요구하는데 kebab 은 VACUUM 을 실행하지 않는다 (#229 항목 참조). 0.4% 를 줄이자고 낼 비용이 아니다.검증
cargo test --workspace --no-fail-fast녹색 (187 ok / 0 FAILED)cargo clippy --workspace --all-targets -- -D warnings녹색시험 항목 (Test Plan)
crates/kebab-store-sqlite/src/derivation_cache.rs:get_many_returns_only_present_keys— 없는 키는 map 에 없고, 중복 키(같은 text 청크 둘)는 접힌다.get_many_is_empty_for_no_keysget_many_spans_more_keys_than_one_statement_holds— 2,000개로 900 단위 분할을 넘긴다. 분할 off-by-one 은 히트를 조용히 미스로 바꿔 "정확성은 멀쩡한데 재임베딩만 하는" 상태를 만든다.put_many_writes_all_and_replaces— 배치 형태도INSERT OR REPLACE의미를 지키는가.put_many_with_no_entries_is_noopcrates/kebab-app/src/ingest_progress.rs:asset_timings_serializes_all_phase_fields에cache_hit/cache_miss/cache_ms추가.곁다리 — #228 에서 내가 넣은 flaky test
ingest_log_records_the_deleted_file_sweep이 두 run 의 로그 중 뒤엣것을 파일명 정렬로 골랐다. run id 가<초 단위 타임스탬프>-<난수 hex>라 같은 초에 끝난 두 run 은 난수 쪽으로 정렬된다. 이번 전체 테스트에서 우연히 터져 잡았고, 첫 run 의 로그 집합을 기록해 두고 차집합으로 고르도록 고쳤다. 연속 5회 통과 확인.버전 영향
wire schema 의 additive minor 변경(
asset_timings신규 필드,#[serde(default)]라 기존 소비자 무영향)이라 major bump 대상이 아니다. 새 서브커맨드·플래그·config 키도 없고 검색·색인 결과도 불변 — 관측성 개선이므로 patch 쪽이다.Assisted-by: Claude Code
리뷰 두 건이 머지 가능으로 결론냈지만, 이 PR 의 핵심이 "실측 근거" 인데 그 근거 쪽에 문제가 있다는 지적이 나왔다. 그쪽을 우선 고친다. 1) cache_ms 가 체계적으로 과소계상돼 있었다 (MEDIUM) 문서 하나당 `as_millis()` 절삭 지점이 3곳(조회 / 삽입 / touch)이었고, 각 구간이 대개 1 ms 미만이라 값이 통째로 사라졌다. 실제로 문서 1,584건 중 **1,422건(90%)이 0 으로 찍혔다**. 초안이 "캐시 경로 전체 0.6초" 를 점추정으로 적고 그 숫자를 근거로 제안 3·6 을 기각했는데, 0.6초는 하한이었다. 내부 누적을 마이크로초로 바꿔 절삭을 emit 시점 1회로 줄였다. 재측정한 구간은 **0.6~2.2초 (run 141.3초의 0.4~1.6%)** 다. 결론은 구간 어느 쪽에서도 같지만, 점추정으로 적어 둘 값은 아니었다. 히트 payload 를 `Vec<f32>` 로 되돌리는 디코드 비용도 캐시 경로에 계상했다. SQL 경계에서 멈추는 지표는 캐시를 실제보다 싸 보이게 한다. 2) embed_ms 를 "Lance upsert" 로만 라벨했다 (MEDIUM) `t_embed` 스팬은 orphan purge + 캐시 경로 + 임베더 + 레코드 구성 + Lance upsert + touch 를 전부 감싼다. 코드 주석 자신이 "purge + upsert" 라고 적고 있는데 HOTFIXES 가 더 좁게 적었다. 그리고 cache_ms 는 embed_ms 의 **부분집합**이지 별도 가산 항목이 아니다. 스키마 설명이 "embedder 호출 제외 — that is embed_ms" 라 두 값이 겹치지 않는 것처럼 읽혔고, 외부 소비자가 phase 를 합산하면 이중 계상한다. "included in embed_ms" 를 명시했다. 3) CacheStats 가 embed_with_cache 의 doc 블록을 가로챘다 (MEDIUM) 구조체를 doc 블록과 `fn` 사이에 끼워 넣어서, 함수 설명 전체가 구조체의 문서가 되고 함수는 문서가 하나도 없는 상태였다. 구조체를 위로 올렸다. 4) 계측의 사각지대를 명시했다 (MEDIUM/LOW) - code 자산은 `asset_timings` 를 아예 emit 하지 않는다(이 PR 이전부터의 공백). 채우려면 code 경로에 parse/chunk/store 타이머를 새로 깔아야 해서 #231 범위 밖이다. 스키마와 DOGFOOD 에 적었다. - `cache_*` 는 임베딩 kind 만 센다. 같은 테이블을 쓰는 OCR·caption 파생은 단건 API 라 안 잡히고, 이미지 위주 코퍼스에서는 캐시가 한 일을 과소 표현한다. 5) README 미갱신 (MEDIUM) `⏱` 줄에 `cache 히트/전체 소요` 세그먼트가 추가됐는데 README 의 ingest 설명이 phase 목록만 적고 있었다. 미반영: `get_many` 의 `prepare_cached` 가 배치 크기마다 SQL 문자열이 달라져 사실상 캐시 미스라는 지적 — 정확하지만 누수도 정확성 문제도 없고, 버킷 패딩은 1% 짜리에 낼 복잡도가 아니다. `put_many` 시그니처의 불필요한 할당, 자산 단위 피크 메모리 2배(자산 단위로 유계) 도 같은 이유로 남긴다. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_017c9JwQq8ZkGvYjpKXMiDhF2회차 리뷰가 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