Skip to content

feat(logging): add a trace tier across all plugins, unlocked by DEBUG#56

Merged
stephane-segning merged 1 commit into
mainfrom
claude/trace-logging
Jun 15, 2026
Merged

feat(logging): add a trace tier across all plugins, unlocked by DEBUG#56
stephane-segning merged 1 commit into
mainfrom
claude/trace-logging

Conversation

@stephane-segning

Copy link
Copy Markdown
Contributor

What

Adds a most-verbose trace log level (priority 5, below debug) to all four plugins, plus ~85 fine-grained trace events at the points worth watching when debugging. Answers "can we get A LOT more logs?" — yes, and they all surface at --log-level DEBUG.

How it's gated

The tier is high-volume, so it isn't a separate host knob: OpenCode's DEBUG now maps to trace (fromOpenCodeLogLevel("DEBUG") → "trace"). Running the host at --log-level DEBUG unlocks the full trace stream on top of the existing debug lifecycle events. A clean run at the default info stays quiet.

OpenCode's client.app.log() enum has no trace, so a trace record is forwarded to the host labelled debug (the finer gating already happened locally); the JSON-console fallback keeps the true trace label. All four plugins converged on this independently.

Events by plugin

  • oauth2 (~26): config-hook steps, providers considered/registered/skipped, token cache load, ensureAccessToken branches (reuse/refresh/interactive), refresh + model-discovery start/finish, per-request bearer injection, scheduler ticks.
  • models-info (~16): per-provider meta parse, cache key/lookup, fetch start, per-model match + field-merge (upstream-wins) decisions, counts.
  • ratelimit (~16): per-provider opt-in, wrapped-fetch invocation + scope bucket key, parsed x-ratelimit triple, throttle/tier selection, pre-emptive wait, 429 backoff/retry, cooldown set/cleared.
  • browser (~28): handshake steps, every frame routed (agent→executor), command dispatch/result/timeout, group ownership (assign/deny/adopt/orphan), executor/agent connect/disconnect, host/guest election.

No secrets: redaction applies to trace like every level; events carry booleans/counts/ids, never raw tokens.

Infra + tests + docs

  • Per package: LogLevel union, LOG_LEVEL_PRIORITY, Logger.trace, console logger, OpenCode wrapper. Plus oauth2 validateLogLevel accepts "trace", and the browser-mcp logger literal gained trace.
  • Each package's logging.test.ts covers DEBUG → trace, trace-emits-at-trace / suppressed-at-debug, and the working trace method.
  • docs/architecture.md → Logging gains a "trace tier" section.

Full pre-push gate green: pnpm -r build && pnpm -r typecheck && pnpm coverage && pnpm lint && pnpm format:check (every per-package coverage threshold still met; 449 tests pass).

Branches off main; independent of #54 and #55 except the shared ## [Unreleased] changelog block (trivial merge).

🤖 Generated with Claude Code

Adds a most-verbose `trace` level (priority 5, below `debug`) to every
plugin's logger, plus ~85 fine-grained trace events at the points you
actually debug:

- oauth2: config-hook steps, providers considered/registered/skipped,
  token cache load + ensureAccessToken decision branches, refresh and
  model-discovery start/finish, per-request bearer injection, scheduler ticks.
- models-info: per-provider meta parse, cache key/lookup, fetch start,
  per-model match + field-merge (upstream-wins) decisions, counts.
- ratelimit: per-provider opt-in, wrapped-fetch invocation + scope bucket,
  parsed x-ratelimit triple, throttle/tier selection, pre-emptive wait,
  429 backoff/retry, cooldown set/cleared.
- browser: handshake steps, every frame routed (agent->executor),
  command dispatch/result/timeout, group ownership (assign/deny/adopt/
  orphan), executor/agent connect/disconnect, host/guest election.

The tier is deliberately high-volume, so it's not its own host knob:
OpenCode's `DEBUG` now maps to `trace` (fromOpenCodeLogLevel("DEBUG") ->
"trace"), so `--log-level DEBUG` unlocks the whole trace stream. Since
OpenCode's client.app.log enum has no `trace`, trace records forward to
the host labelled `debug` (gating already happened locally); the JSON
console fallback keeps the true `trace` label. Secret redaction applies
to trace like every other level — no raw tokens, only booleans/counts/
fingerprints.

Infra (LogLevel union, priority, Logger.trace, console logger, OpenCode
wrapper, oauth2 validateLogLevel, browser-mcp logger literal) + per-plugin
logging tests updated. Docs: architecture.md "Logging" gains a trace
section.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
@chatgpt-codex-connector

Copy link
Copy Markdown

You have reached your Codex usage limits for code reviews. You can see your limits in the Codex usage dashboard.

@gemini-code-assist gemini-code-assist Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

This pull request introduces a new, highly detailed trace log tier across all workspace packages, allowing fine-grained tracking of internal operations when the host is run with --log-level DEBUG. The review feedback focuses on optimizing the performance of the newly added trace logging logic in packages/opencode-models-info/src/plugin.ts by eliminating redundant Map lookups and avoiding double-filtering of array fields.

Important

The consumer version of Gemini Code Assist on GitHub is being sunset. Starting June 18, 2026, new organization installations will be blocked, and all code review activity will officially cease on July 17, 2026.
For more details on the timeline and next steps, please review the Help Documentation.

Comment on lines +107 to +116
const matchById = byId.has(modelId);
const match = byId.get(modelId) ?? (declaredId ? byId.get(declaredId) : undefined);
if (!match) {
deps.logger.trace("models_info_model_unmatched", { providerId, modelId, declaredId });
continue;
}
deps.logger.trace("models_info_model_matched", {
providerId,
modelId,
matchedBy: matchById ? "id" : "declaredId"

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

We can optimize the Map lookups here by retrieving the value directly with byId.get(modelId) instead of calling byId.has(modelId) first. This avoids an extra Map lookup on every iteration of the loop.

Suggested change
const matchById = byId.has(modelId);
const match = byId.get(modelId) ?? (declaredId ? byId.get(declaredId) : undefined);
if (!match) {
deps.logger.trace("models_info_model_unmatched", { providerId, modelId, declaredId });
continue;
}
deps.logger.trace("models_info_model_matched", {
providerId,
modelId,
matchedBy: matchById ? "id" : "declaredId"
const matchFromId = byId.get(modelId);
const match = matchFromId ?? (declaredId ? byId.get(declaredId) : undefined);
if (!match) {
deps.logger.trace("models_info_model_unmatched", { providerId, modelId, declaredId });
continue;
}
deps.logger.trace("models_info_model_matched", {
providerId,
modelId,
matchedBy: matchFromId ? "id" : "declaredId"
});

Comment on lines +119 to +123
const derivedFields = Object.keys(derived);
const appliedFields = derivedFields.filter(
(f) => modelConfig[f] === undefined || overwrite?.has(f)
);
const skippedFields = derivedFields.filter((f) => !appliedFields.includes(f));

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

Evaluating derivedFields.filter twice (including an $O(N)$ .includes check inside the second filter) on every model iteration creates unnecessary array allocations and overhead, even when trace logging is disabled. We can optimize this by partitioning the fields in a single pass.

      const derivedFields = Object.keys(derived);
      const appliedFields: string[] = [];
      const skippedFields: string[] = [];
      for (const f of derivedFields) {
        if (modelConfig[f] === undefined || overwrite?.has(f)) {
          appliedFields.push(f);
        } else {
          skippedFields.push(f);
        }
      }

@stephane-segning stephane-segning merged commit 69e010b into main Jun 15, 2026
3 checks passed
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.

1 participant