sift/docs/implementer-log.md

Implementer log

One row per task session that ends in a commit. Newest last.

Task	Date	Status	Sessions	Gate	Deviations	Summary
p5a/01-kind-fetch	2026-09-25	done	resumed	gate: ok	none	Implemented Kind/application/pdf recognition, PDF body cap (100 MB) and deadline (120 s), and FetchIf with If-None-Match/If-Modified-Since via shared doFetch. Previous session could not pass TestFetchIf only because the given test held its mutex across the handler (deadlock); owner fixed the test. Session resumed after that fix — did not rewrite fetch code, only verified rules and ran gate.
p5a/02-pdftext	2026-09-25	done	1	gate: ok	none	Built the child-extraction package: Extract (reader.Open with ErrWrongPassword→ErrEncrypted, per-page recover, trailer /Info /Title, rule-3 UTF-16BE/Latin-1 decode), outline.go (/Dest and /GoTo /A dests, 10k-item and no-double-visit bounds, never-nil outline), Runner (re-exec'd child, env-isolated via empty env, 60 s deadline, 64 MiB output cap, 200 MiB stdin cap, stderr capped at 4 KiB, exit-code→error mapping, Doc parse plus ErrNoText), and the sift pdftext case in main.go. Removed the tools.go module pin; go.mod/go.sum/vendor/modules.txt confirmed unchanged. All 10 given tests pass under -race -count=3 including the deadline-kill test; make gate ok; given files byte-identical; `printf nope
p5a/03-dcache	2026-09-25	done	1	gate: ok	evict() tie-break	Added the pdf_doc/pdf_page tables, PDFEntry/PDFKey/PutPDF/GetPDF/TouchPDF (one-tx write deleting old pages first, page-ordered read, 304 touch moves only fetched_at), PDFH/PDFM counters, Size() including pdf_doc nbytes. One deviation: extended the eviction union with pdf_doc and added rowid ASC to the ORDER BY so same-second puts evict in insertion order (deterministic whole-document eviction); without it TestPDFEviction is order-dependent. Left Stats() signature unchanged for task 07. Given test byte-identical.
p5a/04-pdfpool	2026-09-25	done	1	gate: ok	none	Implemented the generic scheduler. Pool holds one mutex, a jobs map (key→in-flight job), a callerJobs map (caller→their job), and a FIFO waiters line. Do applies the six rules in order: join (counted in Waiting, no slot, allowed while the caller holds another job, fn may be nil), caller-busy, then slot/queue/refuse. A job's result is broadcast to every sharer via a done channel; results are not cached (key forgotten on finish). fn runs under context.WithoutCancel so the flight outlives a caller that leaves. Panic in fn is recovered into an error, freed the slot and caller. One implementation finding (not a plan deviation): queued jobs must not be counted in Running(), so startLocked only registers a job and a separate takeSlotLocked/grant increments the slot count — abandoning a queued starter (abandon) releases sharers without touching the slot. Given test byte-identical.
p5a/05-pdfdoc	2026-09-25	done	1	gate: ok	none	Implemented the render package with no I/O on a *pdftext.Doc. Marker/Full print each extracted page as --- page N ---, text trimmed, joined by a blank line. Render dispatches grep → page range → whole. Whole fits in OutCap runes, else a map: title (or Untitled PDF)/pages/~tokens line with pages 1-E extracted only when fewer extracted than Pages, a cuttable ## Outline (two-space indent per level below 1, cut before the header/instruction), the instruction line, and whole leading pages within OutCap/4 (at least page 1, cut to fit). Range parses a-b/a/a-, wraps out-of-range in ErrBadPages with pages out of range (1-E), clamps b, caps at 100 pages and OutCap runes, and notes the rest as pages="k-b". Grep is RE2 with smart-case (?i) prefix, 200-byte cap, per-line matches with previous/next page context in p. P-/p. P: form, first 100 shown, total counted; RE2 keeps the (a+)+$ test linear. Every length is in runes. Given test byte-identical; make gate ok.
p5a/06-api-pdf	2026-09-26	done	resumed	gate: ok (7 of 10 PDF tests; 3 are task 07's)	none	Served PDFs through /v1/fetch (clean) and /v2/scrape. Added RetryAfter int to fetch.Error and a Retry-After header line guarded by > 0. Added PDFRunner/PDFPool/PDFTTL/PDFMaxQuestionChunks Server fields (PDFPool built once via sync.Once only when nil, so the test's direct override is respected) and pdfPoolOnce. Routed clean.Kind in doFetch/cleanFetched (html/json/text switched, "other"→415, "pdf"→extractPDF); doFetch's switch routes "text" explicitly so a PDF never runs clean.Text first. New internal/api/pdf.go: DefaultPDFTTL/DefaultPDFMaxQuestionChunks (task 07), runner()/pool() defaults, extractPDF (pool key `callerClass
p5a/08-digest-cli-docs	2026-09-26	done	1	gate: ok	none	Added the page-cite sentence to the digest systemPrompt ("When the document has --- page N --- markers, cite the page of each fact as (p. N).") and set PromptVersion = "3". Added the sift_pdf_extract_total{outcome}, sift_pdf_extract_seconds, sift_pdf_pages_total, sift_pdf_pool_wait_seconds, sift_pdf_cache_hits_total series to internal/metrics (pdf.go package) and wired ObservePDF/ObservePDFWait/PDFCacheHit into internal/api/pdf.go (ObservePDF once per call after extractPDF, outcome classified by pdfOutcome so raw text never becomes a label; ObservePDFWait only when the caller actually waited on pool().Do; PDFCacheHit on fresh hits and 304s). Refactored cmd/sift/fetchcmd.go into a fetchOpts struct with parseFetchOpts (returns fetchOpts, not string, error) and a fetchBody(o fetchOpts) map[string]any that does the digest/clean default and adds pages/grep only when set; --pages/--grep added to fetchValueFlags. Updated skill/SKILL.md (PDFs section; removed PDF mention from the 415 row). Unit: nix/module.nix MemoryMax = "1G" (one line). README: added a "PDF documents" section covering detection, limits (100 MB/120 s download, 60 s extraction, 2,000 pages), the child process, the 2-slot/4-wait/20 s pool, the 24 h conditional-GET cache, the answers, the task-06 errors table, and the metrics; noted the go-pdfkit/extract v0.3.0 engine chosen by the docs/P5a.md §3 bake-off. All tests pass under -race, make gate ok, three given files byte-identical, nix diff is one line.
p5b/01-splitpages-bm25	2026-09-26	done	1	gate: ok	none	splitpages.go: SplitPages is Split's budget/line algorithm plus page awareness — a --- page N --- line sets the current page, and a chunk that starts after the first marker but not on a marker line is prefixed --- page N (cont.) ---\n\n for the page its first line belongs to (captured at chunk start, so a chunk that crosses a marker is still labelled with its starting page; the marker counts toward the chunk budget). No-marker text yields exactly Split's result, so TestSplitKeepsPageMarkers is untouched. bm25.go: BM25 with k1=1.2/b=0.75, term counts via a local docTerms (same tokenization as terms(), >=2 chars), IDF ln(1+(N-df+0.5)/(df+0.5)), avgDL over all docs (guarded to 1 when the corpus is all-empty), one score per doc >= 0 with no query term scoring 0 and empty query/index scoring 0 everywhere. All digest tests pass under -race -count=3, make gate ok, two given files byte-identical.
p5b/02-retrieval	2026-09-26	done	1	gate: ok	none	Cached chunk embeddings + BM25-first retrieval. digest.go: EmbedSyncMax=48, MaxDocChunks=5000; Result gains Retrieval string and Embedded int; selectText now returns (body, used, total, mode, embedded, err) and Run sets both; PutDigest skips storing any mode=="bm25" answer (provisional, not cached). retrieval.go: hybridOrBM25 — no cache, len(chunks)<=48 embeds question+chunks inline and scores hybrid; >48 scores BM25 and queues; cache present embeds the question and only the uncached chunks inline and scores hybrid on the union; both embed paths return hybrid, both bm25 paths return bm25. background.go: bgWorker with bgOnce sync.Once (creates the worker, never starts a goroutine) + w.started under w.mu (starts the goroutine once), dedup by `contentHash
p5a/07-api-cache-pages	2026-09-26	done	1	gate: ok	none	Implemented the PDF document cache with revalidation in doFetch: pdfFromCache (miss / fresh within PDFTTL / stale → FetchIf with 304→TouchPDF+answer-fresh / 200→return response with ok=false and no second GET) and storePDF after extractPDF (ContentHash=res.SHA256, ETag/Last-Modified from headers, FetchedAt=now, Meta=JSON of doc.Meta, Pages=doc.Text). pages/grep passed into pdfdoc.Options in renderPDF; ErrBadPages/ErrBadGrep→400 with the error's own text, non-PDF→400 "pages and grep apply to PDFs only" before the doc block. Question limit in digest mode: n=len(digest.Split(pdfdoc.Full(doc), ChunkTokens)), n>PDFMaxQuestionChunks→422 "document too long for question (n chunks); use grep or pages" before any digest call. Envelope cached set true for cache answers via the synthetic cache res's empty body (len(res.Body)==0); the one doFetch change beyond the rule-1 call was reusing that 200 response instead of a second Fetch. Added fmt import to api.go. Given file byte-identical; make gate ok.
p5b/03-api	2026-09-26	done	1	gate: ok	none	The digest now answers long documents itself (task 02), so the API's refusal limit is only a safety cap: DefaultPDFMaxQuestionChunks 200→5000 in internal/api/pdf.go (the 422 message text unchanged, still "document too long for question (N chunks); use grep or pages"). In v1fetch (internal/api/api.go) the digest-meta map gains "retrieval": dr.Retrieval and "embedded": dr.Embedded next to chunks_used/chunks_total, only when the digest ran without a fallback. Copied the two given tests byte-identical from the plan — the replacement pdf_test.go is now the protected one and asserts DefaultPDFMaxQuestionChunks == 5000; pdf_retrieval_test.go asserts the first long-doc question returns retrieval=bm25, embedded=0. README PDF section: a long-doc question is answered first from BM25 (retrieval: "bm25") while its chunks embed in the background and hybrid on later questions, plus the 5000-chunk cap. One sentence added to skill/SKILL.md. All api tests pass under -race -count=3; make gate ok; given files byte-identical.
p5c/01-extract-api	2026-09-26	done	1	gate: ok	none	POST /v1/extract answers a PDF posted in the body like /v1/fetch answers the same PDF by URL, nothing fetched. internal/api/extract.go: auth via caller; io.ReadAll of the body (a *http.MaxBytesError→413 "too large (>N MB)", empty→400); clean.Kind must be "pdf" else 415; query pages/grep/question/mode (digest when a question is set, else clean; other→400). Content-addressed cache: hash="sha256:"+HashBody(body), key=PDFKey("upload:"+hash, callerClass); a GetPDF hit rebuilds the doc via pdfFromEntry with cached:true + PDFCacheHit and no child (bypasses the TTL/revalidation that pdfFromCache does, so identical content is extracted once); a miss builds a synthetic fetch.Resource{URL:"upload",...} and runs extractPDF+storePDF. Bad pages/grep→400 via writeFetchErr, the chunk limit→the same 422 as v1fetch, extraction errors→pdfError via writeFetchErr. Envelope mirrors the PDF fetch path (content/mode/untrusted/warnings/sizes/timings/pdf/digest); source is {"kind":"upload","hash","bytes","cached","fetched_at"} with no url key; no Honcho context for uploads; one log line "extract" with caller/bytes/pdf_pages/mode/cached. internal/api/api.go scoped to the rule-1 changes: DefaultPDFMaxUpload const (100 MiB), PDFMaxUpload int64 Server field, the POST /v1/extract route in New, and ServeHTTP (per-path upload cap instead of the 64 KiB JSON limit, and /v1/extract added to the requestDeadline switch). The pdfMaxUpload() field-or-default resolver lives in extract.go. Given test byte-identical; all api tests pass under -race -count=3; make gate ok.
p5c/02-extract-cli	2026-09-26	done	1	gate: ok	none	sift extract <file.pdf> uploads a local PDF to /v1/extract and prints the answer exactly as sift fetch does. cmd/sift/extractcmd.go: extractOpts + parseExtractOpts (reuses splitAroundPositional with extractValueFlags mode/pages/grep/question, one positional file, --json), extractURL builds base+"/v1/extract" with url.Values set only for the options that are set and mode=digest when a question is given and no mode — values are URL-encoded so a grep like a b&c survives round-trip; extractMain reuses loadClient, stats the file and refuses >100 MiB before uploading (exit 3, matching the server's 413→exitFor), then http.NewRequest with the *os.File as the streaming body and ContentLength set (no second in-memory copy), Content-Type: application/pdf + bearer, and the same error/exitFor path as fetch; success prints content (or the --json envelope). main.go: case "extract" and one help line. README: extract line in the CLI block plus a sentence; SKILL.md: a PDF-on-disk bullet in the PDFs section. Given test byte-identical; all cmd/sift tests pass under -race -count=3; make gate ok; bin/sift extract prints the usage line.
p6/01-batchstore	2026-09-26	done	1	gate: ok	none	Storage-only batch store in internal/dcache (new batch.go; schema added to Open; BatchH/BatchM counters added to DB). CreateBatchJob stores as given. Reads never write the lease: BatchJob, BatchTargets and the counts are pure, so exact lease values hold after a read. BatchJobByIDem returns the newest (caller,idemKey) job with lease+ttl>now and status queued/running/done/partial; failed/cancelled never reused. PutBatchTargets inserts in order; BatchTargets returns idx order with NULLs as nil pointers. UpdateBatchTarget bumps lease to now, increments targets_done exactly once per target entering done/failed (previous-status check prevents re-write double-count), and adds len(result) to nbytes when a result is written — all in one tx. SetBatchJobStatus/TouchBatchJob set lease; SweepBatch deletes by lease+ttl<=now with its targets and returns the job count; EvictBatchOldest evicts whole non-live jobs oldest-lease-first (never a queued/running one) until BatchNbytes()<=maxBytes; MarkInFlightFailed fails queued/running on restart; BatchNbytes sums job nbytes, kept out of Size(). Accessors return (v,bool)/error, count misses in BatchM, reuse ClassFleet/ClassRestricted. A first pass failed TestBatchIDemLookup because I forgot .Scan(&id) on the QueryRow (the un-scanned *sql.Row was always non-nil, so the method always missed); fixed and verified. All dcache tests pass under -race -count=3; make gate ok; given file byte-identical.
p6/02-runner-core	2026-09-26	done	1	gate: ok	caller-cleanup hand-off to task 03	Runner core in new internal/batch with no workers (task 03 adds them; jobs stay queued, so a queued job counts as live for the caps). Public surface in batch.go: Options/Target/Result/TargetError, FetchFunc, Job/TargetStatus, Hooks and Config with defaults (TTL 24h, 32 targets/job, 1 job/caller, 8 total, worker clamped to 2, 64 MiB, 2 s/10 m retry). Submit runs the given order — empty→ErrNoTargets, idempotency via hex SHA-256 of name+NUL+json.Marshal(targets) (a live hit returns the id reused, touching no caps), then TargetsPerJob/JobsPerCaller/JobsTotal caps, then stores the job queued (random 16-byte hex id, CreatedAt=Lease=now) and its targets (pending, Options=json of t.Options) before returning so a queued job is live; the submitting caller is held in memory by job id, never persisted. Status maps rows and decodes Result without writing; Touch moves the lease; Cancel sets a queued job cancelled at once and leaves its targets pending; Close is idempotent. Store errors are Warn-logged with the job id, never a URL/host.
p6/03-runner-workers	2026-09-26	done	1	gate: ok	none	Workers in new internal/batch/worker.go: one rotation of live jobs in submit order, round-robin via an absolute cursor (advances in pick, wraps at access, so it survives a second job being added while the first is in flight — the mod-n cursor from the design stuck at 0 for one job and re-picked it), serial per job (target i+1 never starts before i is stored), one target per fetch under the Close-cancelled context (panic→ErrInternal, never echoed; ErrRetryLater retried after RetryWait, bounded by RetryFor then stored failed with the wrapped text). Terminal status once per job: all done→done, all failed→failed, mix→partial. Cancel of a running job sets cancelled, stores the in-flight target without overwriting cancelled, leaves later targets pending. Close sets closed, cancels the context, broadcasts, waits the workers, idempotent. batch.go: New starts cfg.Workers, Submit appends the liveJob and wakes, Cancel handles the in-flight case, Close stops. Absolute cursor is the one deviation from the design's "index in live" comment. All race tests pass -count=3.
p6/04-metrics	2026-09-26	done	1	gate: ok	none	Batch series in new internal/metrics/batch.go, registered in New: BatchJobsTotal/BatchTargetsTotal CounterVecs (label "outcome", any value outside the known set folded to "other" via batchJobOutcomes/batchTargetOutcomes maps so a raw string never becomes a label), BatchQueueDepth/BatchTargetsInflight gauges, and BatchJobSeconds/BatchTargetSeconds histograms (durationBuckets) plus BatchResultBytes (1K,4K,16K,64K,256K,1M). Nil-receiver-safe Observe…/Set… methods mirroring ObservePDF/ObserveDigest. Series served through the existing /metrics handler; no new endpoint, no Snapshot change. Given test byte-identical; metrics tests pass under -race -count=3; make gate ok.
p6/05-fetchtarget	2026-09-26	done	1	gate: ok	none	Extracted v1fetch's per-target pipeline into new internal/api/target.go: fetchTarget(ctx, c, t batch.Target) (batch.Result, error). Body moved unchanged in order — question truncation to 500 runes, mode default/check, wantCtx, doFetch, recover path, PDF branch (render, pages/grep errors, question-chunk limit), clean/raw branch, digest, context search, the fetch log line, and the envelope. content is returned as Result.Content; every other envelope key (mode,untrusted,source,warnings,sizes,timings, and pdf/digest/context when present) goes in Result.Meta, never content. v1fetch keeps reqN/caller/decode/400, builds a batch.Target (URL + Mode/Question/Pages/Grep/JQ/Context/Recover into Options), calls fetchTarget, writeFetchErr on error and writeJSON(w,200,env) on success where env is a fresh copy of Meta plus "content" (a copy, so len(env)==len(Meta)+1 holds and Meta is not mutated). The two writeErr failures become *fetch.Error with the same status/msg/hint: 400 "invalid url" (bad mode), 400 "raw mode does not apply to PDFs". doFetch takes context.Context instead of *http.Request (its three r.Context() → ctx); scrape passes r.Context(). Removed now-unused fmt/unicode/utf8/recover imports, added batch. All api tests pass under -race -count=3; make gate ok; given test byte-identical.
p6/06-batch-wiring	2026-09-26	done	1	gate: ok	none	New internal/api/batch.go: NewBatchRunner overwrites cfg.Hooks so Job→ObserveBatchJob, Target→ObserveBatchTarget(batchOutcome)+ObserveBatchTargetSeconds (+ObserveBatchResultBytes only when err==nil), and JobSeconds/Depth/Inflight→the matching s.Prom methods; the runner's FetchFunc is batchFetch, which tags ctx with an unexported batchCtxKey, runs under requestDeadline, and maps fetchTarget's errors (a *fetch.Error 429/503 → fmt.Errorf("%s: %w", fe.Msg, batch.ErrRetryLater) so the runner retries; any other *fetch.Error → TargetError with 502 rewritten to 500 "internal error" and s.blockN.Add(1) for 403; anything else → TargetError 500 logged Error with s.logErr). batchOutcome classifies nil→ok, ErrRetryLater-wrapped→busy, then by TargetError.Status (403 blocked, 429 busy, 504 timeout, 415 unsupported, 422 whose Msg starts "document too long"→too_long, other 4xx→upstream_4xx, 5xx→upstream_5xx, any other error→upstream_5xx). Added Batch *batch.Runner Server field (nil → the /v1/batch endpoints answer 503 "batch disabled"). pdf.go extractPDF charges the PDF pool to c.Name+"/batch" when the ctx carries the batch mark, single-flight key unchanged so a batch and an interactive extract of the same PDF still share one child; the only new log line carries caller and host="-" (never a URL/host). All api tests pass under -race -count=3; make gate ok; given file byte-identical.
p6/07-api-endpoints	2026-09-26	done	1	gate: ok	none	The four /v1/batch handlers in new internal/api/batch.go: batchSubmit (POST) decodes {"targets":[{url,mode,question,pages,grep,jq,context,recover}]} flat like /v1/fetch, 400 "invalid batch" on bad json/empty list/empty url/bad mode (only empty,clean,raw,digest), then PreCheck per target → 422 "blocked: target : " with no job, then Submit mapping ErrTooManyTargets→422 "too many targets (max 32)", ErrCallerBusy→429+Retry-After 30, ErrBusy→429+Retry-After 60, ErrNoTargets→400, and 202 {success,job_id,status,targets,reused} (status "queued" new, current status reused). batchStatus (GET) and batchResult (GET {id}/{idx}) and batchCancel (DELETE) share ownership (unknown or not c.Name → 404, never 403; nil batch → 503); status is a summary with no results unless ?results=1 inlines the envelope (Meta+content) on done targets, idx validated 0..targets_total-1 else 404, cancel of a terminal job → 409 "job already finished" else 200 {success,status:cancelled}. api.go scoped to the rule-2 changes: batchMaxBody (256 KiB) const, the four routes in New, and ServeHTTP applying the per-path cap once (/v1/batch→256 KiB, /v1/extract→pdfMaxUpload, else 64 KiB) and collapsing every batch path to a fixed metrics label via batchObservePath (/v1/batch or /v1/batch/{id}, never a job id). Each handler logs one batch line with caller/job_id/targets/status-or-reused and never a URL/hostname/idem_key. Given test byte-identical; all api tests pass under -race -count=3; make gate ok.

P5a review (owner, 2026-09-26)

Checked: 8 task commits (13365a2 … 7e78de6), each with the Co-Authored-By: ornith-1.5-35b-a3b trailer; every given file byte-identical to its plan copy; internal/guard, internal/auth, go.mod, go.sum, vendor/ untouched; nix/module.nix changed only in MemoryMax; make gate ok; go test -race -count=3 ./... ok.

End-to-end with the real binary, the real guard, a real cache and dixie's 9B for digests, on public PDFs: Attention (15 pp, whole text, 1.9 s), GPT-3 (75 pp, map, 2.6 s), NIST SP 800-63B, the RP2040 datasheet (642 pp, 4.5 s), Karpathy's thesis (14.7 MB, 16 s including download). pages and grep from the cache in about 1.5 ms; a question digest with correct page citations (p. 1, 7, 8) in 11 s; /v2/scrape shape; sift_pdf_* metrics; no title or text in the logs.

#	Finding	Severity	Fault	Fix
1	No outline for any LaTeX (hyperref) or Acrobat PDF — every arXiv paper and the NIST PDF showed 0 items (qpdf: 22–120). Named destinations were skipped (task 02 said to skip them), /Dest//A/titles were not resolved when indirect, and reader's Dict.Get returns reader.Null{} for a missing key, so the /A branch never ran.	high (feature absent on most papers)	task + model	owner: name-tree and /Dests lookup, resolve treats Null as absent, indirect titles; pdftest NamedDests; TestOutlineNamedDestinations (fails on the old code)
2	pool() read PDFPool outside its sync.Once — a data race on concurrent first use with no pool configured (the production default).	medium	model	owner: always through the Once; TestDefaultPoolConcurrentFirstUse (race on the old code)
3	Output over MaxText returned only at the deadline (the runner waited for stderr EOF while the child blocked on a full stdout pipe).	low	model	owner: check size first; TestRunnerTooMuchTextFailsFast (30 s on the old code)
4	Stale-cache revalidation ran outside acquire, so it was not counted against the per-caller/host limit.	low	task (said "before acquire")	owner
5	Fetch Accept lacked application/pdf (P5a §4).	low	task (not in task 01's rules)	owner

Process: 1 owner test deadlock (task 01, 55 min), 1 oversized task (06, looped 3 h, split), 2 hangs from OpenCode 1.15 waiting on a piped stdin (driver fixed), 1 refusal-ending (task 01), 1 malformed tool call (task 04). Every task that ran to the gate passed it first time.