Add fair-use periodic info logs for production visibility

[beastoin]

Summary

Adds info-level logs at key points in the fair-use pipeline so operators can verify the system is actively tracking speech in Cloud Logging.

Info-level logs (steady-state visibility):

• Session start: logs uid, session_id, and current enforcement stage (once per connection)
• Periodic cap check (every 5min): logs rolling daily/3day/weekly speech totals

Debug-level logs (available when needed):

• Periodic speech recording (every 60s): logs speech_ms delta being recorded to Redis
• Session end flush: logs final speech_ms delta on disconnect

Filter in Cloud Logging: jsonPayload.message=~"fair_use:"

Review cycle changes

• Added speech_totals parameter to check_soft_caps() to eliminate duplicate Redis read
• Downgraded high-frequency logs (per-minute recording, session-end flush) to debug level
• Added 2 unit tests covering speech_totals parameter (precomputed vs default path)

Test plan

• Unit tests pass (56/56 in test_fair_use_engine.py)
• No new dependencies — log lines + 1 optional param
• CODEx review: approved (no correctness regression, log volume addressed)
• Reviewer: PR_APPROVED_LGTM
• Tester: TESTS_APPROVED (56/56)
• Deploy to prod → verify fair_use: logs appear in Cloud Logging within 5 minutes

Deploy steps

1. Merge this PR
2. Trigger gcp_backend.yml with environment=prod, branch=main
3. Verify logs: jsonPayload.message=~"fair_use: session start" in Cloud Logging

Ref: #5746

🤖 Generated with Claude Code

[greptile-apps]

Greptile Summary

This PR adds four fair_use:-prefixed info-level log statements to backend/routers/transcribe.py at key points in the fair-use pipeline — session start, periodic speech recording (~60 s), periodic cap check (~5 min), and session-end flush — to give operators visibility into the system's activity via Cloud Logging.

The change is low-risk and purely additive (no new dependencies, no logic changes), but there is one efficiency issue:

• Redundant Redis read on cap check: get_rolling_speech_ms(uid) is called unconditionally before check_soft_caps(uid), but check_soft_caps already calls get_rolling_speech_ms internally. This causes two full Redis round-trips (ZRANGEBYSCORE + HMGET) on every 5-minute periodic check, even in the triggered_caps branch where the pre-fetched speech_totals value is never used. Moving speech_totals = get_rolling_speech_ms(uid) inside the else branch eliminates the wasted read in the triggered-cap path.

Confidence Score: 4/5

• Safe to merge with one minor efficiency fix recommended — no correctness or security issues.
• The change is purely additive log statements with no new dependencies and no altered control flow. The only issue is a redundant Redis read in the cap-check path introduced by calling get_rolling_speech_ms before check_soft_caps (which already calls it internally). This wastes one Redis round-trip per 5-minute interval per active session when a cap is triggered, but does not break functionality.
• backend/routers/transcribe.py — redundant get_rolling_speech_ms call before check_soft_caps at the periodic cap-check block.

Important Files Changed

Filename	Overview
backend/routers/transcribe.py	Adds four fair_use: prefixed info-level log statements across the session lifecycle. One logic issue: get_rolling_speech_ms is called unconditionally before check_soft_caps, but check_soft_caps already calls it internally — creating a redundant double Redis read on every periodic cap check when caps are triggered.

Sequence Diagram

sequenceDiagram
    participant Client
    participant StreamHandler as _stream_handler
    participant FairUse as fair_use.py
    participant Redis

    Client->>StreamHandler: WebSocket connect
    StreamHandler->>FairUse: get_enforcement_stage(uid)
    Note over StreamHandler: LOG: fair_use: session start uid=... stage=...

    loop Every ~60s (_record_usage_periodically)
        StreamHandler->>FairUse: record_speech_ms(uid, speech_ms)
        FairUse->>Redis: ZADD + HINCRBY (bucket)
        Note over StreamHandler: LOG: fair_use: recorded Xms speech uid=...
    end

    loop Every 5min (FAIR_USE_CHECK_INTERVAL_SECONDS)
        StreamHandler->>FairUse: get_rolling_speech_ms(uid)
        FairUse->>Redis: ZRANGEBYSCORE + HMGET
        Note right of FairUse: ⚠️ redundant — check_soft_caps calls this too
        StreamHandler->>FairUse: check_soft_caps(uid)
        FairUse->>Redis: ZRANGEBYSCORE + HMGET (duplicate read)
        alt caps triggered
            Note over StreamHandler: LOG: fair_use: soft cap triggered ...
        else no caps
            Note over StreamHandler: LOG: fair_use: cap check ok daily=... 3day=... weekly=...
        end
    end

    Client->>StreamHandler: WebSocket disconnect
    StreamHandler->>FairUse: record_speech_ms(uid, speech_ms)
    FairUse->>Redis: ZADD + HINCRBY (final flush)
    Note over StreamHandler: LOG: fair_use: session end flush Xms speech uid=...

Loading

_{Last reviewed commit: "Add periodic info lo..."}

[greptile-apps]

Redundant get_rolling_speech_ms Redis call

get_rolling_speech_ms(uid) is called here unconditionally, but check_soft_caps(uid) (called on the very next line) already calls get_rolling_speech_ms internally. This results in two full Redis round-trips (zrangebyscore + hmget) on every 5-minute cap check interval, even when triggered_caps is truthy (where speech_totals is never used).

Since speech_totals is only consumed in the else branch, the extra read is completely wasted when caps are triggered. The fix is to move the call into the else branch:

                    triggered_caps = check_soft_caps(uid)
                    if triggered_caps:
                        logger.info(
                            f'fair_use: soft cap triggered for {uid} session={session_id} caps={triggered_caps}'
                        )
                        asyncio.create_task(trigger_classifier_if_needed(uid, triggered_caps, session_id))
                    else:
                        speech_totals = get_rolling_speech_ms(uid)
                        logger.info(
                            f'fair_use: cap check ok uid={uid} session={session_id}'
                            f' daily={speech_totals["daily_ms"]}ms'
                            f' 3day={speech_totals["three_day_ms"]}ms'
                            f' weekly={speech_totals["weekly_ms"]}ms'
                        )

Alternatively, refactor check_soft_caps to accept and return the computed totals so callers can reuse them.

[beastoin]

All checkpoints passed:

• CP7 Reviewer: PR_APPROVED_LGTM
• CP8 Tester: TESTS_APPROVED (56/56 unit tests)

PR is ready for merge. All changes: 3 files, 21 additions (transcribe.py, fair_use.py, test_fair_use_engine.py).

by AI for @beastoin

[beastoin]

lgtm