fix(cli): show the mascot during cached reports

.github/workflows/upgrade-candidate.yml

@@ -0,0 +1,24 @@
+name: upgrade-candidate
+
+on:
+  pull_request:
+
+permissions:
+  contents: read
+
+jobs:
+  update:
+    name: update (${{ matrix.os }})
+    strategy:
+      fail-fast: false
+      matrix:
+        os: [ubuntu-latest, macos-latest, windows-latest]
+    runs-on: ${{ matrix.os }}
+    steps:
+      - uses: actions/checkout@11bd71901bbe5b1630ceea73d27597364c9af683 # v4.2.2
+      - uses: actions/setup-go@d35c59abb061a4a6fb18e82ac0862c26744d6ab5 # v5.5.0
+        with:
+          go-version: "1.26.10"
+      - name: native update from v0.7.18 to the candidate
+        shell: bash
+        run: bash scripts/candidate-upgrade.sh

CHANGELOG.md

@@ -2,6 +2,8 @@
 
 ## Unreleased
 
+- Interactive reports and `pricing --usage` show the existing mascot on stderr while a cached read is still running. The first frame waits 140ms so a fast command does not flash. `--json`, `--quiet`, pipes, and `TERM=dumb` stay clean. The mascot does not change token totals or avoid a full scan when the cache is missing.
+
 ## 0.7.18 — 2026-11-10 (Alpha)
 
 - Keep measured model identities separate when no public price card exists, including Cursor Grok variants and unresolved `default` routing. Only genuinely missing model names use the unknown-model bucket; prices remain unavailable and token totals do not change. Existing priced aliases still use normalized card identities.

README.md

@@ -260,7 +260,7 @@ Normalized usage data
 CLI / Dashboard / JSON
 ```
 
-whereToken discovers usage information from supported coding agents, normalizes source-specific records into a common representation, and exposes the result through the CLI, dashboard, and JSON output. Later scans reuse a local file index as a cache only; `wheretoken rebuild` deletes that index and reads the agents again.
+whereToken discovers usage information from supported coding agents, normalizes source-specific records into a common representation, and exposes the result through the CLI, dashboard, and JSON output. When macOS Profile refresh is on, an ordinary report reads that normalized index instead of parsing every source again. The output is marked cached and is not a live cloud total. `wheretoken scan` is the full read. `wheretoken rebuild` deletes the index and reads the agents again. See [`docs/performance.md`](docs/performance.md).
 
 It distinguishes the **coding agent** you use from the **provider** that served the model.
 
@@ -306,6 +306,7 @@ whereToken is currently in **alpha**.
 ## Documentation
 
 - CLI reference: [`docs/wheretoken.1`](docs/wheretoken.1)
+- Performance: [`docs/performance.md`](docs/performance.md)
 - Data sources: [`docs/data-sources.md`](docs/data-sources.md)
 - Token accounting: [`docs/token-accounting.md`](docs/token-accounting.md)
 - Cost estimate: [`docs/cost.md`](docs/cost.md)

docs/performance.md

@@ -0,0 +1,113 @@
+# Performance
+
+This note explains why interactive whereToken reports were slow, which changes actually moved the cost, and what is still expensive. It is an engineering reconstruction from the changelog, the current call path, and measurements on one machine. Sentences marked as engineering analysis are not quotes from a commit message.
+
+Speeding up a query is not the same thing as generating newer usage. A cached report does not call provider APIs and does not mean the numbers are the live cloud total.
+
+## What used to be slow
+
+The original report path is still `App.doScan` → `scan.Run`. Every adapter discovers its files and parses them. For Cursor that opens `state.vscdb` and reads `cursorDiskKV` rows whose keys start with `composerData:` and `bubbleId:`. On a machine whose Cursor database has grown for months, that parse dominates a cold report. The product also has to deduplicate by request id, keep account-bound history separate from later accounts, and refuse to show missing usage as zero. A cache that skipped those rules would have been a faster wrong answer.
+
+Engineering analysis: a full scan was a reasonable first design while each tool's local log was small, while the report was the thing that collected data, and while there was no second process allowed to refresh that data. Those assumptions stop holding once one SQLite file is multi-gigabyte and a person runs the CLI many times a day.
+
+## v0.7.13 — query shape, not a cache
+
+v0.7.13 added `wheretoken YYYY-MM-DD` and vendor attribution for Cursor Composer. The changelog for that version says the scheduler, publishing policy, and token accounting did not change. It is not a performance release. Date filters run after events are loaded; they do not avoid reading the sources.
+
+## v0.7.14 — two different changes
+
+### Indexed Cursor reads
+
+`internal/adapter/cursor/cursor.go` documents the mechanism. Cursor's `key` column uses BINARY collation. SQLite's default `LIKE` is case-insensitive, so a prefix `LIKE 'composerData:%'` cannot use that index and walks the table. A case-sensitive `GLOB 'composerData:*'` (and the same for `bubbleId:*`) is an index range. Tests lock the query text. The changelog says this helps a full scan and the interactive fallback, and it explicitly does not claim that an 11 GB database becomes instant.
+
+This is an algorithm/plan change for the scan path. It does not change how often a scan runs.
+
+### Read the normalized index instead of scanning
+
+`internal/cli/report_cache.go` `cachedReport` is the interactive path when all of the following hold:
+
+- the process is macOS
+- Profile auto-refresh is on
+- `App.Scan` is nil and `WHERETOKEN_NO_INDEX` is unset
+- `index.OpenReadOnly` succeeds
+- `ExportCached` returns events and zero integrity gaps
+
+The index stores per-source checkpoints from the last successful scan. It is not one atomic snapshot of every tool, which is why the report prints `缓存报告 · 本地索引数据（扫描时可能分批更新），非实时`.
+
+Confirmed Cursor account history is not inside that file index alone. `ledger.OpenReadOnly` appends ledger rows the index has not seen (`Ledger.Unseen`). The open is `mode=ro`. It does not migrate or write. If the index or the ledger cannot be read, or the export has gaps, `cachedReport` returns not-cached and `runReport` falls through to `doScan`. A broken cache must not look like an empty week.
+
+`wheretoken scan` still parses sources and is what fills the index. `wheretoken rebuild` deletes the index and reads the tools again. Interactive `wheretoken` does not.
+
+This is a caching and scheduling split: collection and reading are different processes. The read is faster because it does not open Cursor's `state.vscdb`. It is staler by design. The background watcher is what is allowed to scan.
+
+### Fewer scans, not a faster scan
+
+`internal/publicprofile/schedule.go` `fixedRefreshSlots` is 00:00, 10:30, and 17:00 in the owner's local time, plus one catch-up if a slot was missed. The watcher sleeps between slots. A repeated wake inside a slot that already finished does not scan again.
+
+That change does not make one scan faster. It cuts how often the expensive scan, the SQLite reads, the filesystem walk, and the profile network publish run. Idle CPU between slots is the watcher sleeping, which is a different claim from "the report got faster."
+
+v0.7.14 also states the publish thresholds (1 token under 1M, 0.01M from 1M, 0.01B from 1B). Those are publication gates, not query performance.
+
+## v0.7.15 — stop background Keychain waits
+
+Unsigned builds can block inside macOS `SecItemCopyMatching` even when the caller asked not to show UI. A scheduled refresh then sits for minutes. `prohibitCursorOSKeychain` on the unattended path refuses OS Keychain unsealing for a sealed Cursor session. Local Cursor activity and other tools still scan. Previously verified account history is reused only when that account has a recorded consent. `wheretoken cursor connect` and a manual `wheretoken scan` still use the interactive authorization path.
+
+This removes a multi-minute stall from the background job. It is not a faster interactive cache read. An owner who has not connected Cursor still does not get invented account tokens.
+
+## v0.7.16 — price reports use the same cache
+
+`runPricingUsage` calls `cachedReport` before `doScan`, same as `runReport`. Before that, `wheretoken` could be a cache read while `wheretoken pricing --usage` parsed every source again, including Cursor. The price table itself did not get cheaper; it stopped repeating the scan.
+
+## v0.7.18 — model identity, not speed
+
+v0.7.18 keeps a measured model id when no public price card matches, and it stops a shorter `--model` query from summing a different unpriced id. Cost is still `price.Event` per event. That work is correctness. It does not remove a scan or an index lookup.
+
+## Why the cache waited until v0.7.14
+
+Engineering analysis, tied to the code that exists now:
+
+- Token totals, request dedupe, and account isolation had to be true before a second copy of those totals was worth reading.
+- The durable ledger and the scan index are the copies. Until those existed and were readable without migrations (`OpenReadOnly`) and without hiding gaps (`ExportCached` gap count), a cache would have been able to show a partial scan as a complete one.
+- The macOS refresh switch is the signal that some other process is allowed to collect. Without that collector, every interactive command still had to be the collector.
+- Once the watcher owns collection, the CLI can be a reader. That is the split.
+
+No commit message records a rejected design. This paragraph is not a claim about what anyone thought at the time.
+
+## What a cached report still spends time on
+
+`cachedReport` calls `metric.Aggregate` before it returns. `runReport` then calls `report.Build`, which aggregates the same events again for the table, calendar, and portrait. Both stay on the interactive path. The resident set is the decoded event slice, not a few index pages.
+
+The mascot on a cached report is the same `scanHUD` sprite used during a full scan. `beginWait` arms it 140ms after the command starts. If the report finishes first, nothing is drawn. Otherwise the ticker repaints every 120ms with the caption `正在整理用量…` and no fake percentage. `finish` erases those rows before the table or JSON is written, so cursor-up cannot eat the result. `--json`, `--quiet`, a non-TTY stdout (a pipe), and `TERM=dumb` do not arm it. A full scan still uses the per-source captions (`正在读 …`) and is not replaced by the generic caption.
+
+`wheretoken scan` remains the command that parses sources. A cached report that misses the index falls back to that scan. The cache is not the live cloud total.
+
+## Measurements
+
+Machine: Apple M4, 24 GiB, Darwin 25.5.0 arm64, local ledger, network not used by these commands. Binary under test for this table: Homebrew `wheretoken 0.7.18`. Command family: cached report (`缓存报告` is in the output). The production Cursor database was not copied and `wheretoken scan` was not run for this table.
+
+Each figure is 7 back-to-back runs. Median is the 4th sorted sample. With 7 samples the nearest-rank 95th percentile is the maximum. `time -l` RSS and CPU are a second series of 7 `wheretoken --quiet` runs, not the TTFB series.
+
+| Path | First stdout byte | Total | User CPU | Max RSS | Scans Cursor? |
+|---|---:|---:|---:|---:|---|
+| v0.7.18 `wheretoken --quiet` | 4583 ms median, max 5763 ms | same as first byte | 4.98 s median user, 4.58 s real | 1.18 GiB median | no (cache hit) |
+| v0.7.18 `--json --quiet` | 4734 ms median, max 8478 ms | same as first byte | not separately sampled | not separately sampled | no |
+| v0.7.18 `wheretoken 2026-11-09 --quiet` | 2571 ms median, max 2696 ms | same as first byte | not separately sampled | not separately sampled | no |
+| Full scan of this machine's Cursor DB | 未测 | 未测 | 未测 | 未测 | would scan; not run |
+| Cached report with the mascot, interactive TTY, `TERM=xterm-256color` | 173 ms median first byte (5 runs: 166, 169, 173, 174, 192) | 5401 ms median total (max 8105 ms) | not sampled separately; quiet non-TTY of the same binary is below | not sampled | no |
+| Same binary, `--quiet`, stdout not a TTY | 4802 ms median total, which is also the first byte | 4802 ms | not sampled | not sampled | no |
+
+The mascot runs are a PTY with both stdout and stderr attached, so the first byte is the sprite, not the table. Those five runs painted the caption 36, 43, 44, 65, and 66 times, then printed the report. `--quiet` on the same binary, with no TTY, stays in the same multi-second band as v0.7.18. The mascot does not remove the aggregate. It moves the first visible byte from the end of the run to about 140ms plus scheduling.
+
+These two series were not paired against the v0.7.18 series on a quiet machine. Do not subtract 4583 from 5401 and call the difference the cost of the sprite.
+
+First stdout byte equals total time on v0.7.18 because `--quiet` prints nothing until aggregation finishes. That is the blank wait. A single idle sample earlier the same night, not part of this 7-run series, printed a human report in 2.27 s. The 7-run series is slower. Treat them as different conditions: the series allocates about 1.2 GiB, seven times, back to back. During the series the 17:00 local refresh slot was also due. After the series the Cursor total was still 9,136,507,911 and the unallocated line was still 1,184,162,802. The ledger file's size changed; the checked token anchors did not.
+
+Do not read the missing full-scan row as "the cache is N times faster than parsing." Those are different operations. The cache avoids the parse. It does not make the parse that `wheretoken scan` still does any cheaper except for the v0.7.14 `GLOB` plan, which was not re-benchmarked here.
+
+## Remaining bottlenecks
+
+- Two aggregates per cached report (`cachedReport` and `report.Build`).
+- The event slice is large enough to push RSS near 1.2 GiB, so the cost is allocation and the portrait/calendar pass, not index I/O alone.
+- A cache miss, `WHERETOKEN_NO_INDEX=1`, refresh switched off, or a gapped index still takes the full scan, including Cursor `state.vscdb` when that file is present.
+- `wheretoken scan` and the three daily refresh slots still do that scan. Fewer times, not zero times.
+- The mascot does not reduce any of the above. It only fills the quiet interval on an interactive terminal.

internal/cli/pricing.go

@@ -239,9 +239,13 @@ func (a *App) writePricingJSON(payload pricingJSON) error {
 // prices every normalized model against the same public card the catalog
 // prints. Unpriced usage stays unavailable — it is never rewritten as $0.
 func (a *App) runPricingUsage(flags Flags, home adapter.Home) int {
+	stop := a.beginWait(flags, reportWaitLabel)
+	defer func() { stop() }()
 	res, cached := a.cachedReport(home)
 	if !cached {
+		stop()
 		res = a.doScan(home, flags.Quiet, flags.Offline, flags.ASCII)
+		stop = a.beginWait(flags, reportWaitLabel)
 	}
 	if a.Scan == nil {
 		restoreBoundCursorHistoryForReport(home, &res)
@@ -265,6 +269,7 @@ func (a *App) runPricingUsage(flags Flags, home adapter.Home) int {
 	}
 	sum := metric.AggregateAt(events, nil, a.Now(), a.Loc)
 	rows := filterUsageModels(sum.ByModel, flags.Vendor, modelQuery)
+	stop()
 	if flags.JSON {
 		payload := catalogPayload(collectPricing(flags.Vendor, flags.Model))
 		payload.Usage = usagePayload(rows, win.Label)

internal/cli/progress.go

@@ -13,6 +13,12 @@ import (
 
 const hudTick = 120 * time.Millisecond
 
+// hudAppearAfter skips the mascot when the command finishes almost
+// immediately. It is not a sleep added to the report.
+const hudAppearAfter = 140 * time.Millisecond
+
+const reportWaitLabel = "正在整理用量…"
+
 type scanHUD struct {
 	w     io.Writer
 	lines int
@@ -26,6 +32,12 @@ type scanHUD struct {
 	hasLast bool
 	stop    chan struct{}
 	ticking bool
+
+	closed bool
+	armed  bool
+	early  chan struct{}
+	wg     sync.WaitGroup
+	done   sync.Once
 }
 
 func (h *scanHUD) clock() time.Time {
@@ -41,6 +53,9 @@ func (h *scanHUD) Show(p scan.Progress) {
 	}
 	h.mu.Lock()
 	defer h.mu.Unlock()
+	if h.closed {
+		return
+	}
 	if h.start.IsZero() {
 		h.start = h.clock()
 	}
@@ -51,9 +66,51 @@ func (h *scanHUD) Show(p scan.Progress) {
 }
 
 func (h *scanHUD) Clear() {
+	h.finish()
+}
+
+// arm shows p after delay unless finish runs first. A fast command therefore
+// does not flash a one-frame mascot. The ticker keeps the existing sprite
+// moving until finish.
+func (h *scanHUD) arm(delay time.Duration, p scan.Progress) {
 	h.mu.Lock()
 	defer h.mu.Unlock()
-	h.stopTickerLocked()
+	if h.armed || h.closed {
+		return
+	}
+	h.armed = true
+	h.early = make(chan struct{})
+	early := h.early
+	h.wg.Add(1)
+	go func() {
+		defer h.wg.Done()
+		timer := time.NewTimer(delay)
+		defer timer.Stop()
+		select {
+		case <-early:
+		case <-timer.C:
+			h.Show(p)
+		}
+	}()
+}
+
+// finish stops the ticker, erases any painted rows, and waits until the
+// delayed first frame can no longer write. A second call does nothing.
+func (h *scanHUD) finish() {
+	h.done.Do(func() {
+		h.mu.Lock()
+		if h.early != nil {
+			close(h.early)
+		}
+		h.closed = true
+		h.stopTickerLocked()
+		h.eraseLocked()
+		h.mu.Unlock()
+		h.wg.Wait()
+	})
+}
+
+func (h *scanHUD) eraseLocked() {
 	if h.lines <= 0 {
 		return
 	}
@@ -118,6 +175,27 @@ func (h *scanHUD) paintLocked() {
 	h.writeBlockLocked(block)
 }
 
+// beginWait arms the existing scan mascot for a cached report or a price
+// table. Quiet, JSON, dumb terminals, and any non-interactive stdout stay
+// silent. The returned stop is idempotent.
+func (a *App) beginWait(flags Flags, label string) func() {
+	if flags.Quiet || flags.JSON || !a.StderrTTY || !a.StdoutTTY {
+		return func() {}
+	}
+	if a.LookupEnv != nil && a.LookupEnv("TERM") == "dumb" {
+		return func() {}
+	}
+	ascii := flags.ASCII || table.UseASCII(false, a.GOOS, a.LookupEnv)
+	h := &scanHUD{
+		w:     a.Stderr,
+		ascii: ascii,
+		color: table.UseColor(flags.NoColor, a.StderrTTY, a.LookupEnv),
+		now:   a.Now,
+	}
+	h.arm(hudAppearAfter, scan.Progress{Label: label, Status: scan.ProgressReading})
+	return h.finish
+}
+
 func (h *scanHUD) writeBlockLocked(block string) {
 	rows := strings.Split(strings.TrimSuffix(block, "\n"), "\n")
 	if len(rows) == 1 && rows[0] == "" {

internal/cli/progress_pty_darwin_test.go

@@ -0,0 +1,42 @@
+//go:build darwin
+
+package cli
+
+import (
+	"bytes"
+	"os"
+	"testing"
+	"unsafe"
+
+	"golang.org/x/sys/unix"
+)
+
+func openPTY(t *testing.T) (master, slave *os.File) {
+	t.Helper()
+	m, err := os.OpenFile("/dev/ptmx", os.O_RDWR, 0)
+	if err != nil {
+		t.Fatal(err)
+	}
+	fd := int(m.Fd())
+	if err := unix.IoctlSetPointerInt(fd, unix.TIOCPTYGRANT, 0); err != nil {
+		m.Close()
+		t.Fatal(err)
+	}
+	if err := unix.IoctlSetPointerInt(fd, unix.TIOCPTYUNLK, 0); err != nil {
+		m.Close()
+		t.Fatal(err)
+	}
+	buf := make([]byte, 128)
+	_, _, errno := unix.Syscall(unix.SYS_IOCTL, uintptr(fd), uintptr(unix.TIOCPTYGNAME), uintptr(unsafe.Pointer(&buf[0])))
+	if errno != 0 {
+		m.Close()
+		t.Fatal(errno)
+	}
+	name := string(buf[:bytes.IndexByte(buf, 0)])
+	s, err := os.OpenFile(name, os.O_RDWR, 0)
+	if err != nil {
+		m.Close()
+		t.Fatal(err)
+	}
+	return m, s
+}

internal/cli/progress_pty_linux_test.go

@@ -0,0 +1,35 @@
+//go:build linux
+
+package cli
+
+import (
+	"fmt"
+	"os"
+	"testing"
+
+	"golang.org/x/sys/unix"
+)
+
+func openPTY(t *testing.T) (master, slave *os.File) {
+	t.Helper()
+	m, err := os.OpenFile("/dev/ptmx", os.O_RDWR, 0)
+	if err != nil {
+		t.Fatal(err)
+	}
+	fd := int(m.Fd())
+	n, err := unix.IoctlGetInt(fd, unix.TIOCGPTN)
+	if err != nil {
+		m.Close()
+		t.Fatal(err)
+	}
+	if err := unix.IoctlSetPointerInt(fd, unix.TIOCSPTLCK, 0); err != nil {
+		m.Close()
+		t.Fatal(err)
+	}
+	s, err := os.OpenFile(fmt.Sprintf("/dev/pts/%d", n), os.O_RDWR, 0)
+	if err != nil {
+		m.Close()
+		t.Fatal(err)
+	}
+	return m, s
+}