Skip to content

[ci] Print opencode's server log in the backport job - #4056

Merged
VaguelySerious merged 1 commit into
mainfrom
peter/backport-opencode-logs
Sep 9, 2026
Merged

VaguelySerious merged 1 commit into
mainfrom
peter/backport-opencode-logs

Conversation

@VaguelySerious

Copy link
Copy Markdown
Member

What

Two changes to .github/workflows/backport.yml, both from investigating why the backport of #4044 failed (run 34382013303).

  1. Both opencode run call sites pass --print-logs.
  2. The comment that reads UnknownError: Unexpected server error as a gateway model_not_found is corrected.

Why

That run failed two seconds into Decide whether to backport with:

Error: {"name":"UnknownError","data":{"message":"Unexpected server error. Check server logs for details.","ref":"err_ab3aa278"}}

The string is opencode's own error middleware, not the AI Gateway. Any unhandled error in an opencode route handler is logged server-side under a random ref and replaced by that generic body, so the message carries no information about the cause by construction, and the ref exists only in a log the job discards.

The cause of that particular run is unrecoverable, but it was not the gateway, the model, or the budget. ai_gateway_request_raw_v3 has no request for it at all, while the two backport runs bracketing it in the same minute, on the same key, model and opencode version, made ten calls between them, all 200. Re-running the identical commit and prompt passed end to end and produced #4054. So: an opencode-side crash before the first model request, and nothing to do but re-run blind.

--print-logs is what makes the next one diagnosable. Verified against 1.18.4 by reproducing the same masked error locally:

level=ERROR message=failed ref=err_02023471 error="ProviderModelNotFoundError: Model not found: ..." cause="...stack..."
Error: {"name":"UnknownError","data":{"message":"Unexpected server error. ...","ref":"err_02023471"}}

The ERROR ... ref=<same ref> line immediately preceding the masked one is exactly what was missing. The log carries no credentials (checked for the key in both streams; GitHub masks registered secrets regardless), and it goes to stderr, so neither step's decision file parsing is affected.

On the comment

The same reproduction shows the existing comment has the mechanism backwards. An unserved slug does surface as this UnknownError, but it is thrown by opencode's own model resolution (ProviderModelNotFoundError from SessionPrompt.getModel) before any request reaches the gateway. And it is one cause among all unhandled route-handler errors. Reading the message as "bad model" sends the next investigator to the gateway, which is where I started and where nothing was wrong.

Tests

No test coverage: this is CI plumbing with no importable surface. Validation was the local 1.18.4 reproduction above, plus actionlint, which reports only the SC2129 style finding that is already present on main (confirmed against git show origin/main:.github/workflows/backport.yml). Empty changeset: no published package changes.

🤖 Generated with Claude Code

opencode masks every unhandled error in its own HTTP server as
`UnknownError: Unexpected server error`, keeping the real error and its
stack in a log the job never captured, under a random `ref` that exists
nowhere else. Pass `--print-logs` at both `opencode run` call sites so
that log reaches the job output.

Run 34382013303 is the case: it failed two seconds into `Decide whether
to backport` with that message and nothing else. The AI Gateway recorded
no request for the run while two backport runs in the same minute, on
the same key and model, succeeded, so the crash was opencode-side and
before the first model request. Re-running the same commit passed, and
the cause is unrecoverable.

Also correct the comment that read the same `UnknownError` as a gateway
`model_not_found`. An unserved slug does throw it, but from
`ProviderModelNotFoundError` in opencode's own model resolution before
any request goes out, and so does every other unhandled error in a route
handler. Reading it as "bad model" points at the gateway when the
gateway is fine.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@VaguelySerious
VaguelySerious requested a review from a team as a code owner September 9, 2026 17:42
@vercel

vercel Bot commented Sep 9, 2026

Copy link
Copy Markdown
Contributor

Your Vercel team Vercel Labs is not permitted to deploy from this git repository. Contact an administrator to add github organization vercel as a Protected Git Scope in Vercel Labs on Vercel. Once added, commit again to see your changes.

Learn more: https://vercel.com/docs/security/protected-git-scopes

@changeset-bot

changeset-bot Bot commented Sep 9, 2026

Copy link
Copy Markdown

🦋 Changeset detected

Latest commit: 43fa847

The changes in this PR will be included in the next version bump.

This PR includes changesets to release 0 packages

When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types

Not sure what this means? Click here to learn what changesets are.

Click here if you're a maintainer who wants to add another changeset to this PR

@github-actions

github-actions Bot commented Sep 9, 2026 •

Copy link
Copy Markdown
Contributor

🧪 E2E Test Results

✅ All tests passed

⚠️ Flaky E2E Tests (passed on retry)

These tests failed at least once and passed on a retry. A recurring entry here is a real race worth investigating.

  • addTenWorkflow (express)
  • addTenWorkflow (tanstack-start)
  • cancelRun via CLI - cancelling a running workflow (sveltekit)
  • promiseRaceWorkflow (nitro)

🛠 Infra Events (absorbed by the harness)

Platform anomalies the e2e harness detected and worked around (e.g. a run the queue never picked up, replaced by a fresh run). Clustered timestamps indicate a backend blip; a steady drip indicates a platform issue worth escalating.

  • cold-start-warmup · suite warmup (tanstack-start) · at 17:45:27Z · abandoned wrun_01M23MBS8AQ13G53KCRK543EVQ
  • run-pickup-stall · plainModuleDoneHook resumed via plain API route (o2flow shape) (nextjs-webpack) · at 17:51:16Z · abandoned wrun_01M23MPTCY30R0GMZVNXCWVWCA

E2E Test Summary

Summary
Passed Failed Skipped Total
✅ 💻 Local Development 3922 0 586 4508
✅ 📦 Local Production 3922 0 586 4508
✅ 🐘 Local Postgres 3922 0 586 4508
✅ 🪟 Windows 320 0 2 322
✅ 🌐 Cross-language Conformance 68 0 74 142
Total 12154 0 1834 13988
Details by Category

✅ 💻 Local Development

App Passed Failed Skipped
✅ astro-stable-node 134 0 27
✅ astro-stable-quickjs 134 0 27
✅ express-stable-node 134 0 27
✅ express-stable-quickjs 134 0 27
✅ fastify-stable-node 134 0 27
✅ fastify-stable-quickjs 134 0 27
✅ hono-stable-node 134 0 27
✅ hono-stable-quickjs 134 0 27
✅ nest-stable-node 134 0 27
✅ nest-stable-quickjs 134 0 27
✅ nextjs-turbopack-canary-node 141 0 20
✅ nextjs-turbopack-canary-quickjs 141 0 20
✅ nextjs-turbopack-stable-node 160 0 1
✅ nextjs-turbopack-stable-quickjs 160 0 1
✅ nextjs-webpack-canary-node 141 0 20
✅ nextjs-webpack-canary-quickjs 141 0 20
✅ nextjs-webpack-stable-node 160 0 1
✅ nextjs-webpack-stable-quickjs 160 0 1
✅ nitro-stable-node 134 0 27
✅ nitro-stable-quickjs 134 0 27
✅ nuxt-stable-node 134 0 27
✅ nuxt-stable-quickjs 134 0 27
✅ sveltekit-stable-node 153 0 8
✅ sveltekit-stable-quickjs 153 0 8
✅ tanstack-start-node 134 0 27
✅ tanstack-start-quickjs 134 0 27
✅ vite-stable-node 134 0 27
✅ vite-stable-quickjs 134 0 27

✅ 📦 Local Production

App Passed Failed Skipped
✅ astro-stable-node 134 0 27
✅ astro-stable-quickjs 134 0 27
✅ express-stable-node 134 0 27
✅ express-stable-quickjs 134 0 27
✅ fastify-stable-node 134 0 27
✅ fastify-stable-quickjs 134 0 27
✅ hono-stable-node 134 0 27
✅ hono-stable-quickjs 134 0 27
✅ nest-stable-node 134 0 27
✅ nest-stable-quickjs 134 0 27
✅ nextjs-turbopack-canary-node 141 0 20
✅ nextjs-turbopack-canary-quickjs 141 0 20
✅ nextjs-turbopack-stable-node 160 0 1
✅ nextjs-turbopack-stable-quickjs 160 0 1
✅ nextjs-webpack-canary-node 141 0 20
✅ nextjs-webpack-canary-quickjs 141 0 20
✅ nextjs-webpack-stable-node 160 0 1
✅ nextjs-webpack-stable-quickjs 160 0 1
✅ nitro-stable-node 134 0 27
✅ nitro-stable-quickjs 134 0 27
✅ nuxt-stable-node 134 0 27
✅ nuxt-stable-quickjs 134 0 27
✅ sveltekit-stable-node 153 0 8
✅ sveltekit-stable-quickjs 153 0 8
✅ tanstack-start-node 134 0 27
✅ tanstack-start-quickjs 134 0 27
✅ vite-stable-node 134 0 27
✅ vite-stable-quickjs 134 0 27

✅ 🐘 Local Postgres

App Passed Failed Skipped
✅ astro-stable-node 134 0 27
✅ astro-stable-quickjs 134 0 27
✅ express-stable-node 134 0 27
✅ express-stable-quickjs 134 0 27
✅ fastify-stable-node 134 0 27
✅ fastify-stable-quickjs 134 0 27
✅ hono-stable-node 134 0 27
✅ hono-stable-quickjs 134 0 27
✅ nest-stable-node 134 0 27
✅ nest-stable-quickjs 134 0 27
✅ nextjs-turbopack-canary-node 141 0 20
✅ nextjs-turbopack-canary-quickjs 141 0 20
✅ nextjs-turbopack-stable-node 160 0 1
✅ nextjs-turbopack-stable-quickjs 160 0 1
✅ nextjs-webpack-canary-node 141 0 20
✅ nextjs-webpack-canary-quickjs 141 0 20
✅ nextjs-webpack-stable-node 160 0 1
✅ nextjs-webpack-stable-quickjs 160 0 1
✅ nitro-stable-node 134 0 27
✅ nitro-stable-quickjs 134 0 27
✅ nuxt-stable-node 134 0 27
✅ nuxt-stable-quickjs 134 0 27
✅ sveltekit-stable-node 153 0 8
✅ sveltekit-stable-quickjs 153 0 8
✅ tanstack-start-node 134 0 27
✅ tanstack-start-quickjs 134 0 27
✅ vite-stable-node 134 0 27
✅ vite-stable-quickjs 134 0 27

✅ 🪟 Windows

App Passed Failed Skipped
✅ nextjs-turbopack-node 160 0 1
✅ nextjs-turbopack-quickjs 160 0 1

✅ 🌐 Cross-language Conformance

App Passed Failed Skipped
✅ python 68 0 74

📋 View full workflow run

@github-actions

github-actions Bot commented Sep 9, 2026 •

Copy link
Copy Markdown
Contributor

📊 Workflow Benchmarks

❌ The benchmark run for 43fa847 failed. See the run logs for details.

No benchmark results were produced.

ℹ️ Metric definitions & methodology

Metrics —

All timestamps are deployment-side; runs are triggered in-deployment, so the CI runner and api.vercel.com sit outside every measured window. TTFS = start() → first step body (includes dispatch + any cold start); Fan-out TTFS/TTLS = first/last step completion of one Promise.all from the same anchor (the gap is the runtime’s fan-out spread); STSO/WO between step bodies; CRTT inside the workflow (excludes the api.vercel.com read path).

Cold starts stay in the numbers (real bursty-workload latency, inflates P75+); Best is the warm floor.

@github-actions

github-actions Bot commented Sep 9, 2026

Copy link
Copy Markdown
Contributor

Sim World

Simulated world deterministic testing for races. Traces

🟠 world-sim scenario book — 1 fail of 41 total

fence=per-spec

scenario outcome events virt replay violations
✅ smoke-no-steps completed 3 0ms ok 0
✅ smoke-one-step completed 6 0ms ok 0
✅ hook-at-step-started completed 12 0ms ok 0
✅ hook-at-step-completed completed 12 0ms ok 0
✅ hook-at-hook-created completed 12 0ms ok 0
✅ deadline-hook-wins completed 7 1.0h ok 0
✅ deadline-expires completed 7 1.0h ok 0
✅ long-sleep completed 11 30.0d ok 0
✅ hook-never-arrives stalled 3 0ms skipped 0
✅ step-retries-twice completed 10 2.0s ok 0
✅ parallel-steps completed 9 0ms ok 0
✅ hook-on-execution-state completed 12 0ms ok 0
✅ peek-hook-before-branch completed 12 0ms ok 0
✅ peek-hook-after-branch completed 12 0ms ok 0
✅ peek-hook-at-registration completed 12 0ms ok 0
✅ race-hook-before-probe completed 12 0ms ok 0
✅ race-hook-after-probe completed 12 0ms ok 0
✅ race-duplicate-delivery completed 13 0ms ok 0
✅ attr-hook-before-step completed 11 0ms ok 0
✅ attr-hook-after-step completed 11 0ms ok 0
✅ attr-from-step-body completed 13 0ms ok 0
✅ fork-hook-after-timeout completed 14 1.0m ok 0
✅ fork-hook-before-timeout completed 14 1.0m ok 0
✅ count-hook-after-timeout completed 17 1.0m ok 0
✅ count-hook-before-timeout completed 20 1.0m ok 0
✅ stale-read-step-count-fork completed 20 1.0m ok 0
✅ stale-read-equal-step-counts completed 14 1.0m ok 0
✅ step-vs-step-fork completed 12 0ms ok 0
✅ step-vs-step-fork-fenced completed 12 0ms ok 0
✅ fence-catches-benign-direction completed 12 5ms ok 0
✅ in-flight-before-decision completed 17 1.0m ok 0
❌ in-flight-before-decision-counted completed 17 1.0m ok 0
✅ in-flight-after-decision completed 19 2.0m ok 0
✅ stale-read-step-count-fork-fenced completed 20 1.0m ok 0
✅ fork-hook-wins completed 13 1.0m ok 0
✅ fork-timeout-wins completed 13 1.0m ok 0
✅ unclaimed-payload-under-fork completed 17 1.0m ok 0
✅ claimed-payload-under-fork completed 17 1.0m ok 0
✅ writers-independent-step-bodies completed 12 0ms ok 0
✅ writers-scripted-tempo completed 12 0ms ok 0
✅ cancel-mid-step cancelled 7 0ms skipped 0

Full trace: world-sim.txt

@github-actions

github-actions Bot commented Sep 9, 2026

Copy link
Copy Markdown
Contributor
Framework Flow route Step reg. Framework output
hono 201.6 KiB (±0) 41.7 KiB (±0) 1.78 MiB (±0)
nextjs-turbopack 207.8 KiB (±0) 439 B (±0) 771.7 KiB (±0)
About these numbers

Sizes are gzip; parentheses show the change against main.
Flow route and Step reg. gate this job, on raw bytes rather than the gzip shown, at max(2%, 50.0 KiB). Framework output is informational.

43fa847 · run

@vercel

vercel Bot commented Sep 9, 2026

Copy link
Copy Markdown
Contributor

The latest updates on your projects. Learn more about Vercel for GitHub.

Project Deployment Actions Updated
workflow-docs Ready Ready Preview, v0 Sep 9, 2026 5:45pm UTC

@VaguelySerious
VaguelySerious merged commit 22b5f48 into main Sep 9, 2026
127 of 186 checks passed
@VaguelySerious
VaguelySerious deleted the peter/backport-opencode-logs branch September 9, 2026 19:18
@github-actions

github-actions Bot commented Sep 9, 2026

Copy link
Copy Markdown
Contributor

No backport to stable for 22b5f48 (AI decision).

The commit only touches .github/workflows/backport.yml (adding --print-logs to the opencode calls and correcting a comment) plus an empty changeset. git ls-tree origin/stable -- .github/workflows/backport.yml returns nothing, so that file does not exist on stable; the backport workflow runs only from main. It is diagnostic CI plumbing for main's own tooling, not something needed to keep stable buildable, testable, or releasable.

To override, re-run the Backport to stable workflow manually via workflow_dispatch and paste this commit SHA into the ref input:

22b5f48e3767f6574f8a6843a251678693d2f950

This branch was successfully deployed

1 active deployment
Preview – workflow-docs — 43fa847e Deployed Sep 9, 2026 by vercel[bot]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants