deckhearth/docs/SCANNER_DEBUG_MODE.md
Randall Stillwell 106bd9d592
Some checks failed
CI / Lint (pull_request) Has been cancelled
CI / Schema map up to date (pull_request) Has been cancelled
CI / Forbidden patterns (9 checks) (pull_request) Has been cancelled
Visual diff / Should run? (pull_request) Has been cancelled
CI / Migrations apply (node-pg-migrate) (pull_request) Has been cancelled
Visual diff / Screenshot diff (pull_request) Has been cancelled
CI / Unit tests (vitest) (pull_request) Has been cancelled
Convoy metrics gate / Require role-event telemetry on convoy PRs (pull_request) Has been cancelled
PR Health rollup / Aggregate gate status (pull_request) Has been cancelled
Preview smoke / Should run? (pull_request) Has been cancelled
Preview smoke / Playwright smoke (pull_request) Has been cancelled
feat(scanner): add debug instrumentation for vision pipeline timing
- Add isDebugMode() + debugLog() helpers to scanner-card-identify.js and use-scanner-identification.js
- Instrument Layer 0 (pgvector), Layer 1 (Tesseract OCR + pg_trgm), Layer 2 (Vision API) with per-layer timing
- Log shutter press, verification outcomes, rate-limit cooldowns, and pipeline totals
- Activate via localStorage.setItem('SCANNER_DEBUG', 'true') or window.__SCANNER_DEBUG = true
- Zero runtime overhead when debug mode is off (isDebugMode() check inlined)
- Add docs/SCANNER_DEBUG_MODE.md with full usage guide and log pattern examples
2026-09-01 17:02:01 -05:00

156 lines
5 KiB
Markdown
Raw Permalink Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

# Scanner Debug Mode
Real-time performance instrumentation for the card scanner pipeline. Use this to diagnose slow identification, rate-limit issues, or layer-specific bottlenecks on iOS Chrome, Mac webcam, or any device.
## Activation
**Method 1: Browser console (temporary)**
```javascript
window.__SCANNER_DEBUG = true
```
**Method 2: localStorage (persists across reloads)**
```javascript
localStorage.setItem('SCANNER_DEBUG', 'true')
```
Then navigate to `/scanner` or reload the page.
## What Gets Logged
Every scanner operation logs timestamped messages with emoji prefixes for quick visual scanning:
### Shutter Press & Overall Timing
```
[Scanner Debug 21:45:32.123] 🎯 Shutter pressed (tracker-42, attempt 1)
[Scanner Debug 21:45:37.456] ✅ Card verified successfully → 5333ms total
```
### Layer 0: pgvector Visual Similarity
```
[Scanner Debug 21:45:32.150] 🔍 Layer 0 (pgvector visual) started
[Scanner Debug 21:45:32.270] ⬆️ Layer 0 escalating → 120ms { reason: 'low confidence' }
```
or
```
[Scanner Debug 21:45:32.270] ✅ Layer 0 resolved → 120ms { card: 'Lightning Bolt', matches: undefined }
```
### Layer 1: Tesseract OCR + pg_trgm
```
[Scanner Debug 21:45:32.280] 📝 Layer 1 (Tesseract OCR + pg_trgm) started
[Scanner Debug 21:45:33.130] 🔤 OCR completed → 850ms { nameText: 'Lightning Bolt', confidence: 88 }
[Scanner Debug 21:45:33.280] ✅ Layer 1 resolved → 1000ms { card: 'Lightning Bolt', matches: 3 }
```
### Layer 2: Vision API (Gemini/OpenAI)
```
[Scanner Debug 21:45:33.290] 🤖 Layer 2 (Vision API) call started
[Scanner Debug 21:45:37.490] ✅ Vision API success → 4200ms { card: 'Lightning Bolt', needsUserSelection: false }
```
### Rate Limit / Cooldown
```
[Scanner Debug 21:45:37.500] 🚫 Rate limit hit (15/min) — cooldown until 21:46:37 → 10ms
```
or
```
[Scanner Debug 21:45:38.000] ⏸️ Vision cooldown active — retry in 59s
```
### Errors
```
[Scanner Debug 21:45:32.500] ⚠️ Layer 0 failed → 220ms { rateLimited: true }
[Scanner Debug 21:45:33.500] ❌ Verification failed (no outcome) → 1000ms
[Scanner Debug 21:45:34.500] 💥 Verification exception → 1200ms { error: 'Network request failed' }
```
## Reading the Output
**Total scan time breakdown:**
- **Layer 0 (pgvector):** Typically 80200ms. If this escalates, L1 runs next.
- **Layer 1 OCR:** Tesseract runs in-browser; expect 6001200ms. If name extraction fails or confidence is low, escalates to L2.
- **Layer 2 Vision API:** Network call to `/api/scan/identify` (Gemini/OpenAI). Typically 28 seconds depending on network + API latency.
**Rate limit (15/min):** The scanner allows 15 vision API calls per minute per user (Redis key `deckhearth:scan:{userId}`). If you hit this, you'll see the cooldown message with the exact retry timestamp.
## Common Patterns
### Fast path (Layer 0 hit)
```
🎯 Shutter pressed
🔍 Layer 0 started
✅ Layer 0 resolved → 120ms
🎉 Pipeline complete (L0) → 125ms total
✅ Card verified successfully → 130ms total
```
### OCR path (Layer 0 miss, Layer 1 hit)
```
🎯 Shutter pressed
🔍 Layer 0 started
⬆️ Layer 0 escalating → 120ms
📝 Layer 1 started
🔤 OCR completed → 850ms
✅ Layer 1 resolved → 1000ms
🎉 Pipeline complete (L1) → 1020ms total
✅ Card verified successfully → 1025ms total
```
### Vision API path (both layers escalate)
```
🎯 Shutter pressed
🔍 Layer 0 started
⬆️ Layer 0 escalating → 120ms
📝 Layer 1 started
🔤 OCR completed → 850ms
⬆️ Layer 1 escalating → 1000ms
🤖 Layer 2 (Vision API) started
✅ Vision API success → 4200ms
🎉 Pipeline complete (L2) → 5320ms total
✅ Card verified successfully → 5325ms total
```
### Rate limit hit
```
🎯 Shutter pressed (attempt 16)
🔍 Layer 0 started
⬆️ Layer 0 escalating → 110ms
📝 Layer 1 started
⬆️ Layer 1 escalating → 950ms
🤖 Layer 2 (Vision API) started
🚫 Vision API rate limited → 80ms
🚫 Pipeline halted (rate limited) → 1140ms total
🚫 Rate limit hit (15/min) — cooldown until 21:46:32 → 1145ms
```
## iOS Chrome Specific Issues
If you see **no logs at all** on iOS Chrome:
1. Open Safari on macOS, connect your iPhone via USB
2. Develop → [Your iPhone] → [deckhearth tab]
3. The Safari Web Inspector console will show the debug logs
If **Layer 0/1 succeed but L2 times out**:
- iOS Chrome network throttling may be active (Settings → Safari → Advanced → Experimental Features)
- Vision API may be slow on cellular — test on Wi-Fi
If **OCR step shows `nameText: ""` repeatedly**:
- Camera capture may be producing black frames on iOS — check canvas output in the inspector
## Deactivation
```javascript
delete window.__SCANNER_DEBUG
localStorage.removeItem('SCANNER_DEBUG')
```
Then reload the page.
## Implementation
Debug logs are injected at:
- `lib/scanner-card-identify.js` — Layer 0/1/2 network calls + pipeline orchestration
- `lib/use-scanner-identification.js` — Shutter press + verification wrapper
The `isDebugMode()` check is inlined in every `debugLog()` call, so there's zero runtime overhead when debug mode is off.