diff --git a/.github/workflows/dev-lead-reusable.yml b/.github/workflows/dev-lead-reusable.yml index 77497664e..88367ebe2 100644 --- a/.github/workflows/dev-lead-reusable.yml +++ b/.github/workflows/dev-lead-reusable.yml @@ -51,6 +51,8 @@ jobs: GEMINI_CLI_TRUST_WORKSPACE: "true" DEV_LEAD_SCRIPTS: .dev-lead/scripts DEV_LEAD_PROMPTS: .dev-lead/prompts/dev-lead + TOKEN_LOG_FILE: /tmp/token-usage-${{ github.run_id }}.jsonl + TOKEN_WORKFLOW: dev-lead steps: - name: Checkout caller repo @@ -255,6 +257,15 @@ jobs: REPO: ${{ github.repository }} run: bash .dev-lead/scripts/dev-lead-fix-reviews.sh + - name: Upload token usage log + if: always() + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 + with: + name: token-usage-${{ github.run_id }} + path: /tmp/token-usage-${{ github.run_id }}.jsonl + if-no-files-found: ignore + retention-days: 30 + # ── ci-relay ────────────────────────────────────────────────────────────────── # Handles check_run completed failure events. No LLM — resolves PR number and # fires repository_dispatch dev-lead-ci-failure back to the calling repo. diff --git a/.github/workflows/issue-triage-runner.yml b/.github/workflows/issue-triage-runner.yml index 527eed603..229af47f2 100644 --- a/.github/workflows/issue-triage-runner.yml +++ b/.github/workflows/issue-triage-runner.yml @@ -27,7 +27,8 @@ jobs: claude_code_oauth_token: ${{ secrets.CLAUDE_CODE_OAUTH_TOKEN }} - name: Install Python dependencies - run: pip install "pyyaml==6.0.3" --only-binary=":all:" --quiet + run: | + pip install "pyyaml==6.0.3" --only-binary=":all:" --quiet - name: Run issue-triage (staged) id: run @@ -62,7 +63,8 @@ jobs: persist-credentials: false - name: Install Python dependencies - run: pip install "pyyaml==6.0.3" --only-binary=":all:" --quiet + run: | + pip install "pyyaml==6.0.3" --only-binary=":all:" --quiet - name: Apply triage output (safe-output) env: diff --git a/.github/workflows/pr-review.yml b/.github/workflows/pr-review.yml index 04656715b..4105f5549 100644 --- a/.github/workflows/pr-review.yml +++ b/.github/workflows/pr-review.yml @@ -163,6 +163,8 @@ jobs: CLAUDE_CODE_VERSION: ${{ vars.CLAUDE_CODE_VERSION || 'latest' }} # Mention-triggered reviews always force a re-review; all other triggers # respect the idempotency check (no double-reviews on the same head SHA). + TOKEN_LOG_FILE: /tmp/token-usage-${{ github.run_id }}.jsonl + TOKEN_WORKFLOW: pr-review FORCE_REVIEW: ${{ github.event_name == 'repository_dispatch' && 'true' || inputs.force_review || 'false' }} steps: @@ -170,7 +172,7 @@ jobs: uses: actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd # v6.0.2 - name: Cache claude-code CLI - uses: actions/cache@v5.0.5 + uses: actions/cache@27d5ce7f107fe9357f9df03efb73ab90386fccae # v5.0.5 with: path: ~/.npm-global key: claude-code-${{ env.CLAUDE_CODE_VERSION }}-${{ runner.os }} @@ -255,3 +257,12 @@ jobs: - name: Review each PR (cascade) run: bash scripts/review-batch.sh + + - name: Upload token usage log + if: always() + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 + with: + name: token-usage-${{ github.run_id }} + path: /tmp/token-usage-${{ github.run_id }}.jsonl + if-no-files-found: ignore + retention-days: 30 diff --git a/.github/workflows/test-dev-lead.yml b/.github/workflows/test-dev-lead.yml index af5fbb139..b6e4fb793 100644 --- a/.github/workflows/test-dev-lead.yml +++ b/.github/workflows/test-dev-lead.yml @@ -4,6 +4,7 @@ on: paths: - 'scripts/dev-lead*' - 'scripts/engine.sh' + - 'scripts/lib/**' - '.github/workflows/dev-lead*.yml' - '.github/workflows/test-dev-lead.yml' - 'tests/dev-lead/**' @@ -13,6 +14,7 @@ on: paths: - 'scripts/dev-lead*' - 'scripts/engine.sh' + - 'scripts/lib/**' - 'tests/dev-lead/**' - 'prompts/dev-lead/**' workflow_dispatch: {} diff --git a/docs/dev-lead/spec.md b/docs/dev-lead/spec.md index b8f1c3dea..422a35f59 100644 --- a/docs/dev-lead/spec.md +++ b/docs/dev-lead/spec.md @@ -184,7 +184,7 @@ The engine is selected once per workflow run. Handler scripts do not hardcode en | Function | Tool access | Use | |---|---|---| | `run_triage ` | No tools | Fast classification, cheap model | -| `run_agentic ` | Bash, Read, Grep, Glob | Analysis with file access | +| `run_agentic [tier]` | Bash, Read, Grep, Glob | Analysis/action/audit with file access | | `run_duck ` | Bash, Read, Grep, Glob | Cross-engine adversarial check | ### 6.3 New engine function: `run_writer()` diff --git a/scripts/engine.sh b/scripts/engine.sh index 6b5280eca..60810d33b 100644 --- a/scripts/engine.sh +++ b/scripts/engine.sh @@ -5,10 +5,16 @@ set -euo pipefail # # Sourced by review-one-pr.sh — provides: # run_triage — no-tool tier (stdout capture) -# run_agentic — full-tool tier (stdout) +# run_agentic [tier] — full-tool tier (stdout) # run_duck — cross-engine adversarial (stdout) # ENGINE_* env vars for model names and labels # DUCK_ENGINE / DUCK_MODEL for rubber-duck cross-engine review +# +# Token logging (opt-in): +# Set TOKEN_LOG_FILE= to capture per-call JSONL token records. +# TOKEN_WORKFLOW — workflow label for records (default: "unknown"). +# Records are written via scripts/lib/token-metrics.sh (estimate-based). +# Unset → zero overhead, zero behaviour change. REVIEW_ENGINE="${REVIEW_ENGINE:-claude}" export REVIEW_ENGINE @@ -90,6 +96,13 @@ set_engine_config() { set_engine_config echo " engine: $REVIEW_ENGINE ($ENGINE_LABEL)" +# Load token metrics library unconditionally (non-fatal). +# emit_token_record and friends are no-ops when TOKEN_LOG_FILE is unset. +_TOKEN_LIB="$(dirname "${BASH_SOURCE[0]}")/lib/token-metrics.sh" +# shellcheck source=lib/token-metrics.sh +[ -f "$_TOKEN_LIB" ] && source "$_TOKEN_LIB" 2>/dev/null || true +unset _TOKEN_LIB + # is_rate_limited # Returns 0 (true) if the text looks like a provider usage/rate-limit block — # API-level (429), subscription/billing caps (plan limit, out of tokens, HTTP 402), @@ -176,6 +189,24 @@ copilot_chat() { -s "$@" < /dev/null } +# _record_engine_tokens [output_file] +# Writes one token record to TOKEN_LOG_FILE using estimate_tokens_from_file. +# No-op when TOKEN_LOG_FILE is unset or the token-metrics library is not loaded. +# Always succeeds (non-fatal): token logging must never abort a real workflow. +_record_engine_tokens() { + [ -n "${TOKEN_LOG_FILE:-}" ] || return 0 + declare -f emit_token_record >/dev/null 2>&1 || return 0 + + local tier="$1" engine="$2" model="$3" prompt_file="$4" output_file="${5:-}" + local workflow="${TOKEN_WORKFLOW:-unknown}" + local input_tokens output_tokens context + input_tokens=$(estimate_tokens_from_file "$prompt_file") + output_tokens=$(estimate_tokens_from_file "$output_file") + context="${PR_URL:-}" + emit_token_record "$workflow" "$tier" "$engine" "$model" \ + "$input_tokens" 0 "$output_tokens" "$context" || true +} + # run_triage # No-tool mode. The prompt file already has all PR context inlined by the # caller (review-one-pr.sh builds it). Every tool is denied so the model @@ -188,28 +219,55 @@ copilot_chat() { run_triage() { local prompt_file="$1" local attempt=1 rc=0 + # Capture output for token estimation when logging is enabled (tee is a no-op otherwise). + local _tok_tmp="" + if [ -n "${TOKEN_LOG_FILE:-}" ]; then + _tok_tmp="$(mktemp 2>/dev/null || true)" + fi while [ "$attempt" -le "$RETRY_MAX_ATTEMPTS" ]; do rc=0 + [ -n "$_tok_tmp" ] && : > "$_tok_tmp" case "$REVIEW_ENGINE" in claude) - timeout "$TRIAGE_TIMEOUT_SEC" claude --print \ - --model "$ENGINE_TRIAGE_MODEL" \ - --disallowed-tools "Bash,Read,Write,Edit,Grep,Glob,WebFetch,WebSearch,Task,TodoWrite,NotebookEdit" \ - < "$prompt_file" || rc=$? + if [ -n "$_tok_tmp" ]; then + timeout "$TRIAGE_TIMEOUT_SEC" claude --print \ + --model "$ENGINE_TRIAGE_MODEL" \ + --disallowed-tools "Bash,Read,Write,Edit,Grep,Glob,WebFetch,WebSearch,Task,TodoWrite,NotebookEdit" \ + < "$prompt_file" | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + timeout "$TRIAGE_TIMEOUT_SEC" claude --print \ + --model "$ENGINE_TRIAGE_MODEL" \ + --disallowed-tools "Bash,Read,Write,Edit,Grep,Glob,WebFetch,WebSearch,Task,TodoWrite,NotebookEdit" \ + < "$prompt_file" || rc=$? + fi ;; gemini) - timeout "$TRIAGE_TIMEOUT_SEC" gemini --prompt "" \ - --model "$ENGINE_TRIAGE_MODEL" \ - --approval-mode auto_edit \ - --output-format text \ - < "$prompt_file" || rc=$? + if [ -n "$_tok_tmp" ]; then + timeout "$TRIAGE_TIMEOUT_SEC" gemini --prompt "" \ + --model "$ENGINE_TRIAGE_MODEL" \ + --approval-mode auto_edit \ + --output-format text \ + < "$prompt_file" | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + timeout "$TRIAGE_TIMEOUT_SEC" gemini --prompt "" \ + --model "$ENGINE_TRIAGE_MODEL" \ + --approval-mode auto_edit \ + --output-format text \ + < "$prompt_file" || rc=$? + fi ;; copilot) # In triage mode, we deny all tools to keep it fast and restricted. - copilot_chat "$prompt_file" "$TRIAGE_TIMEOUT_SEC" --deny-tool "*" || rc=$? + if [ -n "$_tok_tmp" ]; then + copilot_chat "$prompt_file" "$TRIAGE_TIMEOUT_SEC" --deny-tool "*" | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + copilot_chat "$prompt_file" "$TRIAGE_TIMEOUT_SEC" --deny-tool "*" || rc=$? + fi ;; esac if [ "$rc" -eq 0 ]; then + _record_engine_tokens "triage" "$REVIEW_ENGINE" "$ENGINE_TRIAGE_MODEL" "$prompt_file" "$_tok_tmp" + [ -n "$_tok_tmp" ] && rm -f "$_tok_tmp" return 0 fi if [ "$attempt" -lt "$RETRY_MAX_ATTEMPTS" ] && is_transient_failure "$rc"; then @@ -219,12 +277,14 @@ run_triage() { attempt=$((attempt + 1)) continue fi + [ -n "$_tok_tmp" ] && rm -f "$_tok_tmp" return "$rc" done + [ -n "$_tok_tmp" ] && rm -f "$_tok_tmp" return "$rc" } -# run_agentic +# run_agentic [tier] # Full tool access (Bash, Read, Grep, Glob). Output to stdout. # # No retry here: callers redirect stdout to a file, so a retry inside this @@ -236,32 +296,65 @@ run_triage() { run_agentic() { local prompt_file="$1" local model="$2" + local tier="${3:-deep}" + local _tok_tmp="" rc=0 + if [ -n "${TOKEN_LOG_FILE:-}" ]; then + _tok_tmp="$(mktemp 2>/dev/null || true)" + fi case "$REVIEW_ENGINE" in claude) - timeout "$DEEP_TIMEOUT_SEC" claude --print \ - --model "$model" \ - --permission-mode acceptEdits \ - --allowed-tools "Bash,Read,Grep,Glob" \ - < "$prompt_file" + if [ -n "$_tok_tmp" ]; then + timeout "$DEEP_TIMEOUT_SEC" claude --print \ + --model "$model" \ + --permission-mode acceptEdits \ + --allowed-tools "Bash,Read,Grep,Glob" \ + < "$prompt_file" | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + timeout "$DEEP_TIMEOUT_SEC" claude --print \ + --model "$model" \ + --permission-mode acceptEdits \ + --allowed-tools "Bash,Read,Grep,Glob" \ + < "$prompt_file" || rc=$? + fi ;; gemini) - timeout "$DEEP_TIMEOUT_SEC" gemini --prompt "" \ - --model "$model" \ - --approval-mode auto_edit \ - --output-format text \ - < "$prompt_file" + if [ -n "$_tok_tmp" ]; then + timeout "$DEEP_TIMEOUT_SEC" gemini --prompt "" \ + --model "$model" \ + --approval-mode auto_edit \ + --output-format text \ + < "$prompt_file" | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + timeout "$DEEP_TIMEOUT_SEC" gemini --prompt "" \ + --model "$model" \ + --approval-mode auto_edit \ + --output-format text \ + < "$prompt_file" || rc=$? + fi ;; copilot) # Full tool support via GitHub Copilot CLI agentic mode (--yolo). # Stream directly to stdout; tee to OUTPUT_FILE when set. if [ -n "${OUTPUT_FILE:-}" ]; then - copilot_chat "$prompt_file" "$DEEP_TIMEOUT_SEC" --yolo | tee "$OUTPUT_FILE" - return "${PIPESTATUS[0]}" + if [ -n "$_tok_tmp" ]; then + copilot_chat "$prompt_file" "$DEEP_TIMEOUT_SEC" --yolo | tee "$OUTPUT_FILE" "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + copilot_chat "$prompt_file" "$DEEP_TIMEOUT_SEC" --yolo | tee "$OUTPUT_FILE" || rc=${PIPESTATUS[0]} + fi else - copilot_chat "$prompt_file" "$DEEP_TIMEOUT_SEC" --yolo + if [ -n "$_tok_tmp" ]; then + copilot_chat "$prompt_file" "$DEEP_TIMEOUT_SEC" --yolo | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + copilot_chat "$prompt_file" "$DEEP_TIMEOUT_SEC" --yolo || rc=$? + fi fi ;; esac + if [ "$rc" -eq 0 ]; then + _record_engine_tokens "$tier" "$REVIEW_ENGINE" "$model" "$prompt_file" "$_tok_tmp" + fi + [ -n "$_tok_tmp" ] && rm -f "$_tok_tmp" + return "$rc" } # extract_verdict_json @@ -307,41 +400,75 @@ sys.exit(1) run_duck() { local prompt_file="$1" local model="$2" + local _tok_tmp="" rc=0 + if [ -n "${TOKEN_LOG_FILE:-}" ]; then + _tok_tmp="$(mktemp 2>/dev/null || true)" + fi case "$DUCK_ENGINE" in claude) unset COPILOT_GITHUB_TOKEN 2>/dev/null || true unset GOOGLE_API_KEY 2>/dev/null || true - timeout "$DUCK_TIMEOUT_SEC" claude --print \ - --model "$model" \ - --permission-mode acceptEdits \ - --allowed-tools "Bash,Read,Grep,Glob" \ - --max-turns 25 \ - < "$prompt_file" + if [ -n "$_tok_tmp" ]; then + timeout "$DUCK_TIMEOUT_SEC" claude --print \ + --model "$model" \ + --permission-mode acceptEdits \ + --allowed-tools "Bash,Read,Grep,Glob" \ + --max-turns 25 \ + < "$prompt_file" | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + timeout "$DUCK_TIMEOUT_SEC" claude --print \ + --model "$model" \ + --permission-mode acceptEdits \ + --allowed-tools "Bash,Read,Grep,Glob" \ + --max-turns 25 \ + < "$prompt_file" || rc=$? + fi ;; gemini) unset CLAUDE_CODE_OAUTH_TOKEN 2>/dev/null || true unset COPILOT_GITHUB_TOKEN 2>/dev/null || true - timeout "$DUCK_TIMEOUT_SEC" gemini --prompt "" \ - --model "$model" \ - --approval-mode auto_edit \ - --output-format text \ - < "$prompt_file" + if [ -n "$_tok_tmp" ]; then + timeout "$DUCK_TIMEOUT_SEC" gemini --prompt "" \ + --model "$model" \ + --approval-mode auto_edit \ + --output-format text \ + < "$prompt_file" | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + timeout "$DUCK_TIMEOUT_SEC" gemini --prompt "" \ + --model "$model" \ + --approval-mode auto_edit \ + --output-format text \ + < "$prompt_file" || rc=$? + fi ;; copilot) unset CLAUDE_CODE_OAUTH_TOKEN 2>/dev/null || true unset GOOGLE_API_KEY 2>/dev/null || true if [ -n "${OUTPUT_FILE:-}" ]; then - copilot_chat "$prompt_file" "$DUCK_TIMEOUT_SEC" --yolo | tee "$OUTPUT_FILE" - return "${PIPESTATUS[0]}" + if [ -n "$_tok_tmp" ]; then + copilot_chat "$prompt_file" "$DUCK_TIMEOUT_SEC" --yolo | tee "$OUTPUT_FILE" "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + copilot_chat "$prompt_file" "$DUCK_TIMEOUT_SEC" --yolo | tee "$OUTPUT_FILE" || rc=${PIPESTATUS[0]} + fi else - copilot_chat "$prompt_file" "$DUCK_TIMEOUT_SEC" --yolo + if [ -n "$_tok_tmp" ]; then + copilot_chat "$prompt_file" "$DUCK_TIMEOUT_SEC" --yolo | tee "$_tok_tmp" || rc=${PIPESTATUS[0]} + else + copilot_chat "$prompt_file" "$DUCK_TIMEOUT_SEC" --yolo || rc=$? + fi fi ;; *) echo "::error::Unknown DUCK_ENGINE='$DUCK_ENGINE'" >&2 + [ -n "$_tok_tmp" ] && rm -f "$_tok_tmp" return 1 ;; esac + if [ "$rc" -eq 0 ]; then + _record_engine_tokens "duck" "$DUCK_ENGINE" "$model" "$prompt_file" "$_tok_tmp" + fi + [ -n "$_tok_tmp" ] && rm -f "$_tok_tmp" + return "$rc" } # parse_reset_time @@ -400,36 +527,59 @@ run_writer() { # to stdout, not stderr), so is_rate_limited never fired and fallback engines # were never tried. local _tmp rc=0 - _tmp=$(mktemp) + _tmp="$(mktemp 2>/dev/null || true)" case "$REVIEW_ENGINE" in claude) - timeout "$ACTION_TIMEOUT_SEC" claude --print \ - --model "$model" \ - --permission-mode acceptEdits \ - --allowed-tools "Bash,Read,Write,Edit,Grep,Glob,WebFetch" \ - < "$prompt_file" | tee "$_tmp" || rc=${PIPESTATUS[0]} + if [ -n "$_tmp" ]; then + timeout "$ACTION_TIMEOUT_SEC" claude --print \ + --model "$model" \ + --permission-mode acceptEdits \ + --allowed-tools "Bash,Read,Write,Edit,Grep,Glob,WebFetch" \ + < "$prompt_file" | tee "$_tmp" || rc=${PIPESTATUS[0]} + else + timeout "$ACTION_TIMEOUT_SEC" claude --print \ + --model "$model" \ + --permission-mode acceptEdits \ + --allowed-tools "Bash,Read,Write,Edit,Grep,Glob,WebFetch" \ + < "$prompt_file" || rc=$? + fi ;; gemini) - timeout "$ACTION_TIMEOUT_SEC" gemini --prompt "" \ - --model "$model" \ - --approval-mode auto_edit \ - --output-format text \ - < "$prompt_file" | tee "$_tmp" || rc=${PIPESTATUS[0]} + if [ -n "$_tmp" ]; then + timeout "$ACTION_TIMEOUT_SEC" gemini --prompt "" \ + --model "$model" \ + --approval-mode auto_edit \ + --output-format text \ + < "$prompt_file" | tee "$_tmp" || rc=${PIPESTATUS[0]} + else + timeout "$ACTION_TIMEOUT_SEC" gemini --prompt "" \ + --model "$model" \ + --approval-mode auto_edit \ + --output-format text \ + < "$prompt_file" || rc=$? + fi ;; copilot) # Self-sufficient write support via gh copilot --yolo - copilot_chat "$prompt_file" "$ACTION_TIMEOUT_SEC" --yolo | tee "$_tmp" || rc=${PIPESTATUS[0]} + if [ -n "$_tmp" ]; then + copilot_chat "$prompt_file" "$ACTION_TIMEOUT_SEC" --yolo | tee "$_tmp" || rc=${PIPESTATUS[0]} + else + copilot_chat "$prompt_file" "$ACTION_TIMEOUT_SEC" --yolo || rc=$? + fi ;; esac # Map rate-limit to exit code 2 for caller to detect; parse reset time for marker embedding - if [ "$rc" -ne 0 ] && is_rate_limited "$(cat "$_tmp")"; then + if [ "$rc" -ne 0 ] && [ -n "$_tmp" ] && is_rate_limited "$(cat "$_tmp")"; then parse_reset_time "$(cat "$_tmp")" - rm -f "$_tmp" + [ -n "$_tmp" ] && rm -f "$_tmp" return 2 fi - rm -f "$_tmp" + if [ "$rc" -eq 0 ]; then + _record_engine_tokens "writer" "$REVIEW_ENGINE" "$model" "$prompt_file" "$_tmp" + fi + [ -n "$_tmp" ] && rm -f "$_tmp" return "$rc" } diff --git a/scripts/lib/token-metrics.sh b/scripts/lib/token-metrics.sh new file mode 100644 index 000000000..2795c5350 --- /dev/null +++ b/scripts/lib/token-metrics.sh @@ -0,0 +1,99 @@ +#!/usr/bin/env bash +set -euo pipefail + +# Token Metrics Library — Effective Tokens (ET) metric + JSONL logging +# +# Provides cost visibility for the pr-review and dev-lead agents. +# ET formula (GitHub's framework): ET = m × (1.0×I + 0.1×C + 4.0×O) +# I = input tokens, C = cache-read tokens, O = output tokens +# m = model cost multiplier (relative to claude-haiku-4-5 = 1.0) +# +# Usage: +# source scripts/lib/token-metrics.sh +# emit_token_record \ +# +# +# Environment: +# TOKEN_LOG_FILE — path to JSONL output file; unset → all functions are no-ops. +# GITHUB_RUN_ID — included in JSONL records when available. +# +# All functions are safe to call even when TOKEN_LOG_FILE is unset or unwritable. + +# model_multiplier_for +# Returns a float cost multiplier relative to claude-haiku-4-5 = 1.0. +# Prints 1.0 for unknown models (safe default — never fails). +model_multiplier_for() { + local model="$1" + case "$model" in + *haiku*) echo "1.0" ;; + *sonnet*) echo "3.0" ;; + *opus*) echo "15.0" ;; + o4-mini | *o4-mini*) echo "2.0" ;; + *gemini*flash*) echo "0.5" ;; + *gemini*pro*) echo "2.0" ;; + *) echo "1.0" ;; + esac +} + +# calculate_et +# Returns ET = multiplier × (1.0×input + 0.1×cache + 4.0×output), two decimal places. +calculate_et() { + local input="${1:-0}" cache="${2:-0}" output="${3:-0}" mult="${4:-1.0}" + awk "BEGIN { printf \"%.2f\", $mult * (1.0 * $input + 0.1 * $cache + 4.0 * $output) }" +} + +# estimate_tokens_from_file +# Returns ceiling(byte_count / 4) as a rough token estimate (4 chars ≈ 1 token). +# Returns 0 if the file does not exist or is empty. +estimate_tokens_from_file() { + local file="${1:-}" + [ -f "$file" ] || { echo "0"; return 0; } + local chars + chars=$(wc -c < "$file" 2>/dev/null || echo "0") + awk "BEGIN { printf \"%d\", int(($chars + 3) / 4) }" +} + +# emit_token_record +# +# Appends one JSONL record to TOKEN_LOG_FILE. No-op when TOKEN_LOG_FILE is unset. +# Silently swallows I/O errors so token logging never aborts a workflow run. +emit_token_record() { + [ -n "${TOKEN_LOG_FILE:-}" ] || return 0 + + local workflow="$1" tier="$2" engine="$3" model="$4" + local input="${5:-0}" cache="${6:-0}" output="${7:-0}" context="${8:-}" + + local mult et ts run_id record + mult=$(model_multiplier_for "$model") + et=$(calculate_et "$input" "$cache" "$output" "$mult") + ts=$(date -u +%Y-%m-%dT%H:%M:%SZ 2>/dev/null || echo "") + run_id="${GITHUB_RUN_ID:-}" + + record=$(jq -cn \ + --arg ts "$ts" \ + --arg workflow "$workflow" \ + --arg tier "$tier" \ + --arg engine "$engine" \ + --arg model "$model" \ + --arg input "$input" \ + --arg cache "$cache" \ + --arg output "$output" \ + --arg et "$et" \ + --arg run_id "$run_id" \ + --arg context "$context" \ + '{ + ts: $ts, + workflow: $workflow, + tier: $tier, + engine: $engine, + model: $model, + input_tokens: ($input | tonumber? // 0), + cache_read_tokens: ($cache | tonumber? // 0), + output_tokens: ($output | tonumber? // 0), + et: ($et | tonumber? // 0), + run_id: $run_id, + context: $context + }' 2>/dev/null) || return 0 + + printf '%s\n' "$record" >> "$TOKEN_LOG_FILE" 2>/dev/null || true +} diff --git a/scripts/review-one-pr.sh b/scripts/review-one-pr.sh index b5a111f34..7648d6187 100644 --- a/scripts/review-one-pr.sh +++ b/scripts/review-one-pr.sh @@ -419,7 +419,7 @@ if [ "$TRIAGE_ESCALATE" = "false" ]; then SINGLE_LOG="/tmp/cascade/single-review-attempt-${single_attempt}.log" single_rc=0 - run_agentic prompts/single-review.md "$ENGINE_SINGLE_MODEL" \ + run_agentic prompts/single-review.md "$ENGINE_SINGLE_MODEL" "single" \ > "$VERDICT_JSON.raw" 2>"$SINGLE_LOG" || single_rc=$? # Check error category on failure only — guards against false positives from @@ -492,7 +492,7 @@ echo " [tier2] deep review ($ENGINE_DEEP_MODEL) + rubber duck ($DUCK_MODEL vi # or tool-execution noise that could cause false positives. OUTPUT_FILE="/tmp/cascade/deep.json" export OUTPUT_FILE -run_agentic prompts/deep-review.md "$ENGINE_DEEP_MODEL" \ +run_agentic prompts/deep-review.md "$ENGINE_DEEP_MODEL" "deep" \ > /tmp/cascade/deep-stdout.txt 2>/tmp/cascade/deep.log & DEEP_PID=$! @@ -566,7 +566,7 @@ if [ "$DUCK_VALID" = "true" ]; then DUCK_RESULT="$DUCK_OUTPUT" OUTPUT_FILE="/tmp/cascade/combined.json" export DEEP_RESULT DUCK_RESULT OUTPUT_FILE - run_agentic prompts/synthesize-duck.md "$ENGINE_ACTION_MODEL" \ + run_agentic prompts/synthesize-duck.md "$ENGINE_ACTION_MODEL" "action" \ > /tmp/cascade/synth-stdout.txt 2>/tmp/cascade/synth.log || true if [ -s "$OUTPUT_FILE" ] && jq empty "$OUTPUT_FILE" 2>/dev/null; then @@ -612,7 +612,7 @@ if [ "$COMBINED_ESCALATE" != "true" ]; then VERDICT_JSON="/tmp/cascade/cascade-action-verdict.json" OUTPUT_FILE="$VERDICT_JSON" export OUTPUT_FILE - run_agentic prompts/cascade-action.md "$ENGINE_ACTION_MODEL" > "$VERDICT_JSON.raw" 2>/tmp/cascade/action.log || true + run_agentic prompts/cascade-action.md "$ENGINE_ACTION_MODEL" "action" > "$VERDICT_JSON.raw" 2>/tmp/cascade/action.log || true if ! extract_verdict_json "$VERDICT_JSON.raw" "$VERDICT_JSON"; then ACTION_STDOUT=$(cat "$VERDICT_JSON.raw" 2>/dev/null || true) ACTION_STDERR=$(cat /tmp/cascade/action.log 2>/dev/null || true) @@ -650,7 +650,7 @@ export OUTPUT_FILE # Audit tier: separate stdout and stderr to safely detect rate limits without # false positives from PR diff content in stdout. -run_agentic prompts/security-audit.md "$ENGINE_AUDIT_MODEL" \ +run_agentic prompts/security-audit.md "$ENGINE_AUDIT_MODEL" "audit" \ > /tmp/cascade/audit-stdout.txt 2>/tmp/cascade/audit.log || true if [ ! -s "$OUTPUT_FILE" ] || ! jq empty "$OUTPUT_FILE" 2>/dev/null; then @@ -685,7 +685,7 @@ VERDICT_JSON="/tmp/cascade/cascade-action-verdict-audit.json" OUTPUT_FILE="$VERDICT_JSON" export OUTPUT_FILE -run_agentic prompts/cascade-action.md "$ENGINE_ACTION_MODEL" > "$VERDICT_JSON.raw" 2>/tmp/cascade/action-audit.log || true +run_agentic prompts/cascade-action.md "$ENGINE_ACTION_MODEL" "action" > "$VERDICT_JSON.raw" 2>/tmp/cascade/action-audit.log || true if ! extract_verdict_json "$VERDICT_JSON.raw" "$VERDICT_JSON"; then ACTION_STDOUT=$(cat "$VERDICT_JSON.raw" 2>/dev/null || true) ACTION_STDERR=$(cat /tmp/cascade/action-audit.log 2>/dev/null || true) diff --git a/tests/dev-lead/unit/test_engine_writer.bats b/tests/dev-lead/unit/test_engine_writer.bats index a94e3652b..29067b3a9 100644 --- a/tests/dev-lead/unit/test_engine_writer.bats +++ b/tests/dev-lead/unit/test_engine_writer.bats @@ -24,6 +24,10 @@ setup() { teardown() { rm -f "$GITHUB_ENV" "$GITHUB_OUTPUT" "$TEST_PROMPT" rm -rf "$STUB_BIN_DIR" + if [ -n "${TEST_OWNED_TOKEN_LOG:-}" ] && [ "${TOKEN_LOG_FILE:-}" = "$TEST_OWNED_TOKEN_LOG" ]; then + rm -f "$TEST_OWNED_TOKEN_LOG" + fi + unset TOKEN_LOG_FILE TEST_OWNED_TOKEN_LOG } # Helper: source engine with a given engine type (suppresses info line) @@ -255,3 +259,169 @@ STUB result=$(cat /tmp/dev-lead-rate-limit-reset) [ -z "$result" ] } + +# ── token logging tests ─────────────────────────────────────────────────────── + +@test "token: run_writer writes a record to TOKEN_LOG_FILE when set" { + _source_engine "claude" + export STUB_ENGINE_EXIT=0 + export STUB_ENGINE_RESPONSE="fixed the bug" + export DEV_LEAD_DRY_RUN=false + local log; log=$(mktemp) + export TOKEN_LOG_FILE="$log" + export TEST_OWNED_TOKEN_LOG="$log" + + run run_writer "$TEST_PROMPT" + + [ "$status" -eq 0 ] + [ -s "$log" ] + jq empty < "$log" +} + +@test "token: run_writer record contains tier=writer" { + _source_engine "claude" + export STUB_ENGINE_EXIT=0 + export DEV_LEAD_DRY_RUN=false + local log; log=$(mktemp) + export TOKEN_LOG_FILE="$log" + export TEST_OWNED_TOKEN_LOG="$log" + + run_writer "$TEST_PROMPT" + + local tier; tier=$(jq -r '.tier' < "$log") + [ "$tier" = "writer" ] +} + +@test "token: run_writer record contains correct engine and model" { + _source_engine "claude" + export STUB_ENGINE_EXIT=0 + export DEV_LEAD_DRY_RUN=false + local log; log=$(mktemp) + export TOKEN_LOG_FILE="$log" + export TEST_OWNED_TOKEN_LOG="$log" + + run_writer "$TEST_PROMPT" + + local engine model + engine=$(jq -r '.engine' < "$log") + model=$(jq -r '.model' < "$log") + [ "$engine" = "claude" ] + [ "$model" = "$ENGINE_ACTION_MODEL" ] +} + +@test "token: run_writer is a no-op for token logging when TOKEN_LOG_FILE unset" { + _source_engine "claude" + export STUB_ENGINE_EXIT=0 + export DEV_LEAD_DRY_RUN=false + unset TOKEN_LOG_FILE + + run run_writer "$TEST_PROMPT" + + [ "$status" -eq 0 ] +} + +@test "token: dry-run does not write a token record" { + _source_engine "claude" + export DEV_LEAD_DRY_RUN=true + local log; log=$(mktemp) + export TOKEN_LOG_FILE="$log" + export TEST_OWNED_TOKEN_LOG="$log" + + run run_writer "$TEST_PROMPT" + + [ "$status" -eq 0 ] + # Log should remain empty (dry-run produces no engine call) + [ ! -s "$log" ] +} + +@test "token: run_writer token capture is non-fatal on unwritable log path" { + _source_engine "claude" + export STUB_ENGINE_EXIT=0 + export DEV_LEAD_DRY_RUN=false + export TOKEN_LOG_FILE="/proc/nonexistent-readonly-path/token.jsonl" + + run run_writer "$TEST_PROMPT" + + [ "$status" -eq 0 ] +} + +@test "token: run_triage writes a record to TOKEN_LOG_FILE when set" { + _source_engine "claude" + export STUB_ENGINE_EXIT=0 + export STUB_ENGINE_RESPONSE="LOW risk verdict" + local log; log=$(mktemp) + export TOKEN_LOG_FILE="$log" + export TEST_OWNED_TOKEN_LOG="$log" + + run run_triage "$TEST_PROMPT" + + [ "$status" -eq 0 ] + [ -s "$log" ] + jq empty < "$log" + local tier; tier=$(jq -r '.tier' < "$log") + [ "$tier" = "triage" ] +} + +@test "token: run_triage is a no-op for token logging when TOKEN_LOG_FILE unset" { + _source_engine "claude" + export STUB_ENGINE_EXIT=0 + unset TOKEN_LOG_FILE + + run run_triage "$TEST_PROMPT" + + [ "$status" -eq 0 ] +} + +@test "token: run_writer_with_fallback logs the fallback engine (not rate-limited primary)" { + _source_engine "claude" + export DEV_LEAD_DRY_RUN=false + local log; log=$(mktemp) + export TOKEN_LOG_FILE="$log" + export TEST_OWNED_TOKEN_LOG="$log" + + # Make claude output rate-limit text (exit 1 → is_rate_limited → returns 2) + cat > "$STUB_BIN_DIR/claude" << 'STUB' +#!/usr/bin/env bash +echo "hit your limit" +exit 1 +STUB + chmod +x "$STUB_BIN_DIR/claude" + + # Gemini stub succeeds + export STUB_ENGINE_EXIT=0 + export STUB_ENGINE_RESPONSE="gemini fixed it" + + run run_writer_with_fallback "$TEST_PROMPT" + + [ "$status" -eq 0 ] + # Token record must exist and belong to the gemini fallback, not claude + [ -s "$log" ] + jq empty < "$log" + local engine tier + engine=$(jq -r '.engine' < "$log") + tier=$(jq -r '.tier' < "$log") + [ "$engine" = "gemini" ] + [ "$tier" = "writer" ] +} + +@test "token: rate-limited primary engine writes NO token record" { + _source_engine "claude" + export DEV_LEAD_DRY_RUN=false + local log; log=$(mktemp) + export TOKEN_LOG_FILE="$log" + export TEST_OWNED_TOKEN_LOG="$log" + + # Claude outputs rate-limit text → run_writer returns 2 and must not log tokens + cat > "$STUB_BIN_DIR/claude" << 'STUB' +#!/usr/bin/env bash +echo "hit your limit" +exit 1 +STUB + chmod +x "$STUB_BIN_DIR/claude" + + run run_writer "$TEST_PROMPT" + + [ "$status" -eq 2 ] + # Rate-limited → no successful completion → token log must be empty + [ ! -s "$log" ] +} diff --git a/tests/dev-lead/unit/test_token_metrics.bats b/tests/dev-lead/unit/test_token_metrics.bats new file mode 100644 index 000000000..4276a53a6 --- /dev/null +++ b/tests/dev-lead/unit/test_token_metrics.bats @@ -0,0 +1,237 @@ +#!/usr/bin/env bats +# Unit tests for scripts/lib/token-metrics.sh (TDD — written before implementation) + +SCRIPT_DIR="$(cd "$(dirname "$BATS_TEST_FILENAME")/../../.." && pwd)" +TOKEN_LIB="$SCRIPT_DIR/scripts/lib/token-metrics.sh" + +setup() { + # shellcheck source=../../../scripts/lib/token-metrics.sh + source "$TOKEN_LIB" + TOKEN_LOG_FILE="$(mktemp)" + export TOKEN_LOG_FILE +} + +teardown() { + [ -n "${TOKEN_LOG_FILE:-}" ] && rm -f "$TOKEN_LOG_FILE" + unset TOKEN_LOG_FILE +} + +# ── model_multiplier_for ────────────────────────────────────────────────────── + +@test "model_multiplier_for: haiku 4.5 returns 1.0" { + run model_multiplier_for "claude-haiku-4-5-20251001" + [ "$status" -eq 0 ] + [ "$output" = "1.0" ] +} + +@test "model_multiplier_for: sonnet 4.6 returns 3.0" { + run model_multiplier_for "claude-sonnet-4-6" + [ "$status" -eq 0 ] + [ "$output" = "3.0" ] +} + +@test "model_multiplier_for: opus 4.7 returns 15.0" { + run model_multiplier_for "claude-opus-4-7" + [ "$status" -eq 0 ] + [ "$output" = "15.0" ] +} + +@test "model_multiplier_for: o4-mini returns 2.0" { + run model_multiplier_for "o4-mini" + [ "$status" -eq 0 ] + [ "$output" = "2.0" ] +} + +@test "model_multiplier_for: gemini-2.0-flash returns 0.5" { + run model_multiplier_for "gemini-2.0-flash" + [ "$status" -eq 0 ] + [ "$output" = "0.5" ] +} + +@test "model_multiplier_for: gemini-1.5-pro returns 2.0" { + run model_multiplier_for "gemini-1.5-pro" + [ "$status" -eq 0 ] + [ "$output" = "2.0" ] +} + +@test "model_multiplier_for: unknown model returns safe default 1.0" { + run model_multiplier_for "some-future-model-v99" + [ "$status" -eq 0 ] + [ "$output" = "1.0" ] +} + +# ── calculate_et ────────────────────────────────────────────────────────────── + +@test "calculate_et: I=1000 C=500 O=100 m=1.0 → 1450.00" { + run calculate_et 1000 500 100 1.0 + [ "$status" -eq 0 ] + [ "$output" = "1450.00" ] +} + +@test "calculate_et: sonnet multiplier I=1000 C=500 O=100 m=3.0 → 4350.00" { + run calculate_et 1000 500 100 3.0 + [ "$status" -eq 0 ] + [ "$output" = "4350.00" ] +} + +@test "calculate_et: zero tokens returns 0.00" { + run calculate_et 0 0 0 1.0 + [ "$status" -eq 0 ] + [ "$output" = "0.00" ] +} + +@test "calculate_et: output tokens weighted 4x: I=0 C=0 O=100 m=1.0 → 400.00" { + run calculate_et 0 0 100 1.0 + [ "$status" -eq 0 ] + [ "$output" = "400.00" ] +} + +@test "calculate_et: cache tokens weighted 0.1x: I=0 C=1000 O=0 m=1.0 → 100.00" { + run calculate_et 0 1000 0 1.0 + [ "$status" -eq 0 ] + [ "$output" = "100.00" ] +} + +@test "calculate_et: opus audit example: I=1000 C=500 O=100 m=15.0 → 21750.00" { + run calculate_et 1000 500 100 15.0 + [ "$status" -eq 0 ] + [ "$output" = "21750.00" ] +} + +# ── estimate_tokens_from_file ───────────────────────────────────────────────── + +@test "estimate_tokens_from_file: 400 chars → 100 tokens" { + local f + f=$(mktemp) + python3 -c "import sys; sys.stdout.write('a' * 400)" > "$f" + run estimate_tokens_from_file "$f" + rm -f "$f" + [ "$status" -eq 0 ] + [ "$output" = "100" ] +} + +@test "estimate_tokens_from_file: non-existent file returns 0" { + run estimate_tokens_from_file "/tmp/nonexistent-$$-absent.txt" + [ "$status" -eq 0 ] + [ "$output" = "0" ] +} + +@test "estimate_tokens_from_file: empty file returns 0" { + local f + f=$(mktemp) + run estimate_tokens_from_file "$f" + rm -f "$f" + [ "$status" -eq 0 ] + [ "$output" = "0" ] +} + +@test "estimate_tokens_from_file: 1 char → 1 token (ceiling division)" { + local f + f=$(mktemp) + printf 'x' > "$f" + run estimate_tokens_from_file "$f" + rm -f "$f" + [ "$status" -eq 0 ] + [ "$output" = "1" ] +} + +@test "estimate_tokens_from_file: 3 chars → 1 token (ceiling: ceil(3/4)=1)" { + local f + f=$(mktemp) + printf 'abc' > "$f" + run estimate_tokens_from_file "$f" + rm -f "$f" + [ "$status" -eq 0 ] + [ "$output" = "1" ] +} + +# ── emit_token_record ───────────────────────────────────────────────────────── + +@test "emit_token_record: appends a valid JSONL line to TOKEN_LOG_FILE" { + emit_token_record "pr-review" "triage" "claude" "claude-haiku-4-5-20251001" 1000 200 100 "" + [ -s "$TOKEN_LOG_FILE" ] + jq empty < "$TOKEN_LOG_FILE" +} + +@test "emit_token_record: record contains correct workflow and tier fields" { + emit_token_record "pr-review" "triage" "claude" "claude-haiku-4-5-20251001" 1000 200 100 "" + local workflow tier + workflow=$(jq -r '.workflow' < "$TOKEN_LOG_FILE") + tier=$(jq -r '.tier' < "$TOKEN_LOG_FILE") + [ "$workflow" = "pr-review" ] + [ "$tier" = "triage" ] +} + +@test "emit_token_record: record contains correct engine and model fields" { + emit_token_record "dev-lead" "writer" "claude" "claude-sonnet-4-6" 2000 500 150 "" + local engine model + engine=$(jq -r '.engine' < "$TOKEN_LOG_FILE") + model=$(jq -r '.model' < "$TOKEN_LOG_FILE") + [ "$engine" = "claude" ] + [ "$model" = "claude-sonnet-4-6" ] +} + +@test "emit_token_record: et value matches formula for haiku" { + # m=1.0, I=1000, C=200, O=100 → ET = 1.0*(1000 + 0.1*200 + 4*100) = 1420.00 + emit_token_record "pr-review" "triage" "claude" "claude-haiku-4-5-20251001" 1000 200 100 "" + local et + et=$(jq -r '.et' < "$TOKEN_LOG_FILE") + [ "$et" = "1420.00" ] +} + +@test "emit_token_record: et value matches formula for opus" { + # m=15.0, I=1000, C=500, O=100 → ET = 15.0*(1000+50+400) = 21750.00 + emit_token_record "pr-review" "audit" "claude" "claude-opus-4-7" 1000 500 100 "" + local et + et=$(jq -r '.et' < "$TOKEN_LOG_FILE") + [ "$et" = "21750.00" ] +} + +@test "emit_token_record: is a no-op when TOKEN_LOG_FILE is unset" { + unset TOKEN_LOG_FILE + run emit_token_record "pr-review" "triage" "claude" "haiku" 100 0 50 "" + [ "$status" -eq 0 ] + [ -z "$output" ] +} + +@test "emit_token_record: appends on multiple calls without truncating" { + emit_token_record "pr-review" "triage" "claude" "claude-haiku-4-5-20251001" 100 0 50 "" + emit_token_record "pr-review" "deep" "claude" "claude-sonnet-4-6" 5000 1000 200 "" + local count + count=$(wc -l < "$TOKEN_LOG_FILE") + [ "$count" -eq 2 ] + while IFS= read -r line; do + echo "$line" | jq empty + done < "$TOKEN_LOG_FILE" +} + +@test "emit_token_record: ts field is a non-empty ISO-8601 timestamp" { + emit_token_record "dev-lead" "writer" "claude" "claude-sonnet-4-6" 2000 500 150 "" + local ts + ts=$(jq -r '.ts' < "$TOKEN_LOG_FILE") + [ -n "$ts" ] + [[ "$ts" =~ ^[0-9]{4}-[0-9]{2}-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}Z$ ]] +} + +@test "emit_token_record: includes context field (pr_url)" { + emit_token_record "pr-review" "deep" "claude" "claude-sonnet-4-6" 5000 0 300 "https://github.com/org/repo/pull/42" + local context + context=$(jq -r '.context' < "$TOKEN_LOG_FILE") + [ "$context" = "https://github.com/org/repo/pull/42" ] +} + +@test "emit_token_record: escapes quoted and multiline context as valid JSONL" { + local context='line "one" +line two' + emit_token_record "pr-review" "deep" "claude" "claude-sonnet-4-6" 5000 0 300 "$context" + jq empty < "$TOKEN_LOG_FILE" + local parsed + parsed=$(jq -r '.context' < "$TOKEN_LOG_FILE") + [ "$parsed" = "$context" ] +} + +@test "emit_token_record: is non-fatal when TOKEN_LOG_FILE path is unwritable" { + export TOKEN_LOG_FILE="/proc/nonexistent-readonly-path/token.jsonl" + run emit_token_record "pr-review" "triage" "claude" "haiku" 100 0 50 "" + [ "$status" -eq 0 ] +}