diff --git a/.github/workflows/token-report.yml b/.github/workflows/token-report.yml index 087f7e794..aac49dcef 100644 --- a/.github/workflows/token-report.yml +++ b/.github/workflows/token-report.yml @@ -42,7 +42,9 @@ concurrency: jobs: report: runs-on: ubuntu-latest - timeout-minutes: 30 + # 60m (was 30m, #954) is a safety margin; the real fix is the bounded-parallel, + # per-download-timeout collection in scripts/token_report.sh. + timeout-minutes: 60 env: ORG: ${{ inputs.org || 'petry-projects' }} LOOKBACK_DAYS: ${{ inputs.lookback_days || '7' }} @@ -63,7 +65,8 @@ jobs: bash scripts/token_report.sh >> "$GITHUB_STEP_SUMMARY" - name: Post report to tracking issue - if: hashFiles('token_report.md') != '' + # Only on a successful generation that actually wrote the report file. + if: ${{ success() && hashFiles('token_report.md') != '' }} uses: actions/github-script@3a2844b7e9c422d3c10d287c895573f7108da1b3 # v9.0.0 with: github-token: ${{ github.token }} @@ -117,3 +120,43 @@ jobs: issue_number: issue.number, body: report, }); core.notice(`Posted weekly token report: ${comment.data.html_url}`); + + - name: Alert tracking issue on failed/timed-out generation + # Fail loudly (#954): a timed-out (job-cancelled) or failed report run used to + # silently skip the post step, leaving a quiet gap in the tracking issue. + # Post a visible alert instead so a regression is noticed. + if: ${{ failure() || cancelled() }} + uses: actions/github-script@3a2844b7e9c422d3c10d287c895573f7108da1b3 # v9.0.0 + with: + github-token: ${{ github.token }} + script: | + const runUrl = `${process.env.GITHUB_SERVER_URL}/${process.env.GITHUB_REPOSITORY}/actions/runs/${process.env.GITHUB_RUN_ID}`; + const LABEL = 'token-report'; + const TITLE = '📊 Token Cost Observatory — Weekly Report'; + + // Locate the existing tracking issue — don't create one just to alert. + const existing = await github.paginate(github.rest.issues.listForRepo, { + owner: context.repo.owner, repo: context.repo.repo, + labels: LABEL, state: 'open', per_page: 100, + }); + const issue = existing.find(i => i.title === TITLE); + if (!issue) { + core.warning(`Token report generation failed and no tracking issue was found to alert. Run: ${runUrl}`); + return; + } + + const body = [ + '⚠️ **Token Cost Observatory — report generation failed.**', + '', + 'This weekly run did not produce a report (collection timed out or the job failed), ' + + 'so no fresh report was posted. ' + + `See the [workflow run](${runUrl}) for details.`, + '', + '_Posted automatically so a failed run is visible rather than a silent gap (#954)._', + ].join('\n'); + + const comment = await github.rest.issues.createComment({ + owner: context.repo.owner, repo: context.repo.repo, + issue_number: issue.number, body, + }); + core.notice(`Posted token report failure alert: ${comment.data.html_url}`); diff --git a/scripts/token_report.sh b/scripts/token_report.sh index 99a06624f..e46af00e1 100755 --- a/scripts/token_report.sh +++ b/scripts/token_report.sh @@ -23,6 +23,12 @@ # GH_TOKEN — PAT with actions:read across the org (artifacts are per-repo) # TOKEN_REPORT_OUT — optional path; when set, the report is written there in addition # to stdout. +# ARTIFACT_OP_TIMEOUT — per-gh-call timeout in seconds (default 60) so one hung/slow +# artifact download or listing cannot consume the whole job. 0 +# disables the wrapper. +# COLLECT_CONCURRENCY — max concurrent artifact listings/downloads (default 8). The +# bulk of collection wall-clock is serial network I/O, so bounded +# parallelism is what keeps the run inside the job timeout. # # ET formula (GitHub's framework): ET = m × (1.0×I + 0.1×C + 4.0×O) # The `et` field is precomputed per call by token-metrics.sh; this script only sums it. @@ -320,6 +326,24 @@ render_token_report() { # Network I/O (main) # --------------------------------------------------------------------------- +# Per-gh-call timeout (seconds) and collection concurrency. See the header. +ARTIFACT_OP_TIMEOUT="${ARTIFACT_OP_TIMEOUT:-60}" +COLLECT_CONCURRENCY="${COLLECT_CONCURRENCY:-8}" + +# _gh_timeout +# Runs `gh "$@"` under a per-call timeout so a single hung/slow request cannot +# stall the whole run (#954). Returns 124 when the call is killed by timeout. +# When ARTIFACT_OP_TIMEOUT is 0 or the `timeout` binary is unavailable, gh runs +# unwrapped. gh is invoked via `bash -c` so an exported shell-function stub (used +# by the unit tests) is still resolved under `timeout`, which only execs binaries. +_gh_timeout() { + if [ "${ARTIFACT_OP_TIMEOUT:-0}" -gt 0 ] && command -v timeout >/dev/null 2>&1; then + timeout "${ARTIFACT_OP_TIMEOUT}" bash -c 'gh "$@"' _ "$@" + else + gh "$@" + fi +} + # _extract_zip # Extracts a zip using unzip when available, else a python3 fallback (CI runners # have unzip; the fallback keeps the script runnable in minimal environments). @@ -336,76 +360,129 @@ PY fi } +# _list_repo_artifacts +# Lists token-usage artifact IDs in one repo that fall inside the lookback window +# and appends " " lines to a unique file in COLLECT_LIST_DIR. Each +# worker writes its own file (no shared-fd contention) so the listings can run in +# parallel. Reads CUTOFF / COLLECT_LIST_DIR from the environment. Always exits 0: +# a failed listing degrades to a WARN + a skipped repo, never an aborted run. +_list_repo_artifacts() { + local repo="$1" arts out + arts="$(_gh_timeout api "repos/${repo}/actions/artifacts" --paginate 2>/dev/null \ + | jq -r --arg cutoff "$CUTOFF" \ + '.artifacts[] | select(.name | startswith("token-usage-")) | select(.expired == false) | select(.created_at >= $cutoff) | .id | tostring')" || { + echo "WARN: could not fetch artifacts for ${repo} — skipping (check actions:read permission or timed out)" >&2 + return 0 + } + [ -n "$arts" ] || return 0 + out="$(mktemp "${COLLECT_LIST_DIR}/list.XXXXXX")" || { + echo "WARN: failed to create temporary file in ${COLLECT_LIST_DIR} — skipping ${repo}" >&2 + return 0 + } + local id + while IFS= read -r id; do + [ -n "$id" ] || continue + printf '%s %s\n' "$repo" "$id" >> "$out" + done <<< "$arts" +} + +# _collect_one_artifact +# Downloads + extracts one artifact and writes its repo-tagged JSONL records into +# COLLECT_JSONL_DIR, touching a marker in COLLECT_MARKER_DIR when ≥1 record is +# written (the caller counts markers for artifact_count). Bounded by _gh_timeout +# so a single hung download is skipped, not waited out. Each worker writes only +# id-scoped paths (artifact IDs are globally unique on GitHub) so parallel workers +# never collide. Reads COLLECT_* from the environment. Always exits 0. +_collect_one_artifact() { + local repo="$1" id="$2" + local zip="$COLLECT_WORKDIR/a-$id.zip" ex="$COLLECT_WORKDIR/x-$id" + mkdir -p "$ex" + if ! _gh_timeout api "repos/${repo}/actions/artifacts/${id}/zip" > "$zip" 2>/dev/null; then + echo "WARN: artifact ${id} from ${repo} — download failed or timed out; skipping (report may be incomplete)" >&2 + rm -rf "$zip" "$ex" + return 0 + fi + if ! _extract_zip "$zip" "$ex" 2>/dev/null; then + echo "WARN: artifact ${id} from ${repo} — extraction failed; skipping (report may be incomplete)" >&2 + rm -rf "$zip" "$ex" + return 0 + fi + + local found=false f dest + while IFS= read -r f; do + # Tag each record with its source repo for the by-repo rollup. + dest="$COLLECT_JSONL_DIR/${id}-$(basename "$f")" + if jq -c --arg repo "$repo" 'select(type=="object") | . + {repo: $repo}' \ + "$f" > "$dest" 2>/dev/null; then + found=true + else + # jq creates the destination before it can fail on malformed input; + # remove it so annotate_records never sees a corrupt *.jsonl file. + rm -f "$dest" 2>/dev/null || true + fi + done < <(find "$ex" -type f -name '*.jsonl' -print) + [ "$found" = true ] && : > "$COLLECT_MARKER_DIR/$id" + + rm -rf "$zip" "$ex" + return 0 +} + # collect_org_jsonl (stdout: " ") -# Discovers non-archived repos, downloads each token-usage artifact inside the -# lookback window, extracts its JSONL, and tags every record with its source repo. +# Discovers non-archived repos, then — in two bounded-parallel passes — lists each +# repo's in-window token-usage artifacts and downloads/extracts them, tagging every +# record with its source repo. Per-call timeouts (_gh_timeout) bound any single +# hung request; COLLECT_CONCURRENCY bounds the fan-out (#954). collect_org_jsonl() { local jsonl_dir="$1" mkdir -p "$jsonl_dir" local repos_raw - if ! repos_raw="$(gh api "orgs/${ORG}/repos?per_page=100&type=all" --paginate \ + if ! repos_raw="$(_gh_timeout api "orgs/${ORG}/repos?per_page=100&type=all" --paginate \ --jq '.[] | select(.archived == false) | .full_name')"; then echo "ERROR: org repo discovery for '${ORG}' failed — verify GH_TOKEN has org read access." >&2 return 1 fi [ -n "$repos_raw" ] || { echo "0 0"; return 0; } - local cutoff repo_count=0 artifact_count=0 - cutoff="$(date -u -d "${LOOKBACK_DAYS} days ago" +%Y-%m-%dT%H:%M:%SZ 2>/dev/null \ - || date -u -v-"${LOOKBACK_DAYS}"d +%Y-%m-%dT%H:%M:%SZ)" + local repo_count + repo_count="$(printf '%s\n' "$repos_raw" | awk 'NF{c++} END{print c+0}')" - local workdir; workdir="$(mktemp -d)" + # Shared state for the parallel workers, all under one workdir for cleanup. + local workdir; workdir="$(mktemp -d)" || { + echo "ERROR: failed to create temporary directory" >&2 + return 1 + } # shellcheck disable=SC2064 trap "rm -rf '$workdir'" RETURN + CUTOFF="$(date -u -d "${LOOKBACK_DAYS} days ago" +%Y-%m-%dT%H:%M:%SZ 2>/dev/null \ + || date -u -v-"${LOOKBACK_DAYS}"d +%Y-%m-%dT%H:%M:%SZ)" + # ARTIFACT_OP_TIMEOUT is read by _gh_timeout *inside* the xargs workers, so it + # must be exported or the per-download timeout silently disables in the fan-out. + export ARTIFACT_OP_TIMEOUT + export CUTOFF COLLECT_JSONL_DIR="$jsonl_dir" COLLECT_WORKDIR="$workdir" + export COLLECT_LIST_DIR="$workdir/list" COLLECT_MARKER_DIR="$workdir/markers" + mkdir -p "$COLLECT_LIST_DIR" "$COLLECT_MARKER_DIR" + export -f _list_repo_artifacts _collect_one_artifact _gh_timeout _extract_zip + + # Pass 1 — list artifacts across all repos in parallel (one worker per repo). + # pipefail in the worker so a failed `gh | jq` listing surfaces as the WARN path + # rather than being masked by jq's success on empty input. + printf '%s\n' "$repos_raw" \ + | xargs -P "$COLLECT_CONCURRENCY" -I {} \ + bash -c 'set -o pipefail; _list_repo_artifacts "$1"' _ {} \ + || true + + # Pass 2 — download + extract each " " pair in parallel. + local worklist="$workdir/worklist" + find "$COLLECT_LIST_DIR" -type f -exec cat {} + > "$worklist" 2>/dev/null || true + if [ -s "$worklist" ]; then + xargs -P "$COLLECT_CONCURRENCY" -n 2 \ + bash -c '_collect_one_artifact "$1" "$2"' _ < "$worklist" \ + || true + fi - local repo - while IFS= read -r repo; do - [ -n "$repo" ] || continue - repo_count=$((repo_count + 1)) - - local arts - arts="$(gh api "repos/${repo}/actions/artifacts" --paginate 2>/dev/null \ - | jq -r --arg cutoff "$cutoff" \ - '.artifacts[] | select(.name | startswith("token-usage-")) | select(.expired == false) | select(.created_at >= $cutoff) | .id | tostring')" || { - echo "WARN: could not fetch artifacts for ${repo} — skipping (check actions:read permission)" >&2 - continue - } - [ -n "$arts" ] || continue - - local id - while IFS= read -r id; do - [ -n "$id" ] || continue - - local zip="$workdir/a-$id.zip" ex="$workdir/x-$id" - mkdir -p "$ex" - if ! gh api "repos/${repo}/actions/artifacts/${id}/zip" > "$zip" 2>/dev/null; then - echo "WARN: artifact ${id} from ${repo} — download failed; skipping (report may be incomplete)" >&2 - continue - fi - if ! _extract_zip "$zip" "$ex" 2>/dev/null; then - echo "WARN: artifact ${id} from ${repo} — extraction failed; skipping (report may be incomplete)" >&2 - continue - fi - - local found=false f dest - while IFS= read -r f; do - # Tag each record with its source repo for the by-repo rollup. - dest="$jsonl_dir/${id}-$(basename "$f")" - if jq -c --arg repo "$repo" 'select(type=="object") | . + {repo: $repo}' \ - "$f" > "$dest" 2>/dev/null; then - found=true - else - # jq creates the destination before it can fail on malformed input; - # remove it so annotate_records never sees a corrupt *.jsonl file. - rm -f "$dest" 2>/dev/null || true - fi - done < <(find "$ex" -type f -name '*.jsonl' -print) - [ "$found" = true ] && artifact_count=$((artifact_count + 1)) - - rm -rf "$zip" "$ex" - done <<< "$arts" - done <<< "$repos_raw" + local artifact_count + artifact_count="$(find "$COLLECT_MARKER_DIR" -type f | wc -l | tr -d ' ')" echo "${repo_count} ${artifact_count}" } diff --git a/tests/token_report.bats b/tests/token_report.bats index cb4cfbdca..1f9f57923 100644 --- a/tests/token_report.bats +++ b/tests/token_report.bats @@ -293,3 +293,85 @@ setup() { [[ "$output" == *"WARN"* ]] [[ "$output" == *"download failed"* ]] } + +# --------------------------------------------------------------------------- +# _gh_timeout — per-call timeout wrapper (#954: one hung gh call must not +# consume the whole job) +# --------------------------------------------------------------------------- + +@test "_gh_timeout: bounds a hung gh call (returns 124, well under the sleep)" { + command -v timeout >/dev/null 2>&1 || skip "timeout command not available" + run bash -c " + gh() { sleep 20; } + export -f gh + source '${BATS_TEST_DIRNAME}/../scripts/token_report.sh' + export ARTIFACT_OP_TIMEOUT=1 + start=\$(date +%s) + if _gh_timeout api anything; then rc=0; else rc=\$?; fi + end=\$(date +%s) + echo \"rc=\$rc elapsed=\$((end - start))\" + " + [[ "$output" == *"rc=124"* ]] + elapsed="$(printf '%s\n' "$output" | sed -n 's/.*elapsed=\([0-9]*\).*/\1/p')" + [ "$elapsed" -lt 10 ] +} + +@test "_gh_timeout: ARTIFACT_OP_TIMEOUT=0 runs gh directly (no timeout wrapper)" { + run bash -c " + gh() { echo \"called:\$1:\$2\"; return 0; } + export -f gh + source '${BATS_TEST_DIRNAME}/../scripts/token_report.sh' + export ARTIFACT_OP_TIMEOUT=0 + _gh_timeout api repos/x/y + " + [ "$status" -eq 0 ] + [[ "$output" == *"called:api:repos/x/y"* ]] +} + +@test "collect_org_jsonl: a hung artifact download times out without stalling; healthy artifact still collected" { + command -v timeout >/dev/null 2>&1 || skip "timeout command not available" + local jsonl_dir fixdir fixzip + jsonl_dir="$(mktemp -d)" + fixdir="$(mktemp -d)" + fixzip="$fixdir/good.zip" + python3 - "$fixzip" <<'PY' +import sys, zipfile +rec = '{"ts":"2099-01-01T00:00:00Z","workflow":"pr-review","tier":"deep","model":"claude-opus-4-7","input_tokens":10,"output_tokens":5,"context":""}\n' +with zipfile.ZipFile(sys.argv[1], "w") as z: + z.writestr("token-usage.jsonl", rec) +PY + run bash -c " + export FIXZIP='$fixzip' + gh() { + case \"\$2\" in + orgs/*/repos*) echo 'petry-projects/test-repo'; return 0;; + repos/*/actions/artifacts/111/zip) cat \"\$FIXZIP\"; return 0;; + repos/*/actions/artifacts/999/zip) sleep 20; return 0;; + repos/*/actions/artifacts*) + printf '{\"artifacts\":[{\"name\":\"token-usage-a\",\"id\":111,\"expired\":false,\"created_at\":\"2099-01-01T00:00:00Z\"},{\"name\":\"token-usage-b\",\"id\":999,\"expired\":false,\"created_at\":\"2099-01-01T00:00:00Z\"}]}' + return 0;; + *) return 0;; + esac + } + export -f gh + source '${BATS_TEST_DIRNAME}/../scripts/token_report.sh' + export ORG=petry-projects LOOKBACK_DAYS=3650 COLLECT_CONCURRENCY=4 + # Deliberately NOT exported: collect_org_jsonl must propagate it to the workers + # itself, or the per-download timeout silently disables in the parallel fan-out. + ARTIFACT_OP_TIMEOUT=1 + start=\$(date +%s) + collect_org_jsonl '$jsonl_dir'; rc=\$? + end=\$(date +%s) + echo \"rc=\$rc elapsed=\$((end - start))\" + " 2>&1 + local recs; recs="$(cat "$jsonl_dir"/111-*.jsonl 2>/dev/null | wc -l | tr -d ' ')" + rm -rf "$jsonl_dir" "$fixdir" + [ "$status" -eq 0 ] + [[ "$output" == *"rc=0"* ]] + # The healthy artifact (111) was downloaded, extracted and repo-tagged. + [ "$recs" -ge 1 ] + # The hung download (999) was bounded, not waited out for its full 20s. + [[ "$output" == *"WARN"* ]] + elapsed="$(printf '%s\n' "$output" | sed -n 's/.*elapsed=\([0-9]*\).*/\1/p')" + [ "$elapsed" -lt 15 ] +}