Skip to content

Fix: pin the test log level inside the vitest workers, not in globalSetup - #349

Open
AmaadMartin wants to merge 5 commits into
fix/hermetic-unit-test-envfrom
fix/vitest-worker-log-level-pin
Open

Fix: pin the test log level inside the vitest workers, not in globalSetup#349
AmaadMartin wants to merge 5 commits into
fix/hermetic-unit-test-envfrom
fix/vitest-worker-log-level-pin

Conversation

@AmaadMartin

@AmaadMartin AmaadMartin commented Jul 31, 2026

Copy link
Copy Markdown
Owner

Please ensure you have read the contribution guide before creating a pull request.

Link to Issue or Description of Change

  1. Link to an existing issue (if applicable):
    Closes: #issue_number
    Related: #issue_number

No tracking issue. The ineffective pin this PR repairs was introduced in google#120 ("chore: mute @google/adk logs while running tests").

  1. Or, if no issue exists, describe the change:

Problem: tests/global_setup.ts calls setLogLevel(LogLevel.ERROR) to mute @google/adk logs during the test suite. It never worked. A vitest globalSetup module runs once, in the Vitest main process, while every test file runs in a separate forked worker (default pool forks, isolate: true). The level is module-level state — setLogLevel mutates currentLogger (core/src/utils/logger.ts:119), whose SimpleLogger holds private logLevel = LogLevel.INFO (core/src/utils/logger.ts:35). Module state does not survive the fork, so each worker started fresh at INFO and the call mutated a logger no test ever used. teardown() was dead for the same reason.

Measured on core/test/plugins before the fix: 10 INFO: [ADK] ... lines of noise (e.g. Plugin 'plugin1' registered.).

A second symptom: because globalSetup runs in the main process, the project alias does not apply to it, so on an unbuilt tree the file aborted the entire run with Failed to resolve entry for package "@google/adk".

Solution: Move the pin into a per-project setupFiles module, which vitest evaluates inside each worker before the test file. tests/global_setup.ts is deleted and globalSetup removed.

  • Why not root-level setupFiles: Vitest 3.2 inline projects entries do not inherit root test options, so a root-level entry simply never runs.
  • Why not extends: true: it would change inheritance for every root option at once (coverage, poolOptions, include) — too large a blast radius for a bug fix, and no smaller (still six added lines).
  • Why the entry is repeated six times: that is this file's existing convention; the 4-line alias block is already repeated six times. Hoisting it into a shared constant was deliberately left alone because a separate open PR already owns that refactor.
  • Why the setup file imports ../core/src/utils/logger.js and not @google/adk: this is the one non-obvious part. A setup file is evaluated before the test module, so importing the public barrel there instantiates the real core module graph before a test file's hoisted vi.mock calls can replace any of it. Measured: with the barrel import, 103 test files / 110 tests failed (unmocked Runner, unmocked express, real UUIDs instead of mock-uuid). Importing only the logger module pulls in logger.ts + winston and nothing else, and the whole suite passes. The comment in the file records this so the "cleanup" to a barrel import is not made later.

No file under core/src/, dev/src/ or integrations/src/ is touched; there is no public API change and the shipped packages are unaffected. Only the test harness changes.

Collision check (required before implementation): gh pr list --repo AmaadMartin/adk-js --state open --limit 100 plus gh pr diff --name-only on every vitest-adjacent PR (#343, #341, #324, #311, #302, #281, #261). No PR lands this change. One genuinely overlaps: #302 fix/hermetic-unit-test-env adds setupFiles to the same three unit project entries. Two independent setupFiles: keys added to the same object literal would merge into a duplicate key and break the config, so this PR is stacked on fix/hermetic-unit-test-env rather than branched from main, and extends its array instead of adding a second key. Its base must stay that branch until #302 merges.

Testing Plan

Please describe the tests that you ran to verify your changes. This is required for all PRs that are not small documentation or typo fixes.

Unit Tests:
[x] I have added or updated unit tests for my change.
[x] All unit tests pass locally.

Added one new file, core/test/utils/log_level_pin_test.ts (project unit:core, which CI runs). No existing test was modified or deleted. SimpleLogger.logLevel is private and there is no read accessor, and reaching in with getLogger()['logLevel'] is not acceptable, so the test observes the level the only public way — by capturing what the logger writes. Winston's Console transport writes to the stream held by whatever globalThis.console is at log time, so the helper swaps in a node:console Console bound to an in-memory Writable; vi.spyOn(process.stdout, 'write') and vi.spyOn(console, 'log') capture nothing here because vitest replaces the global console with its own instance backed by a private stream.

Proof each test can fail (both mutations run against the final code):

  1. Pre-fix baseline. The test file was written and run before vitest.config.ts was touched. suppresses info logs failed verbatim:

    AssertionError: expected '\u001b[32mINFO\u001b[39m: [ADK] 2026-…' to be '' // Object.is equality
    
    - Expected
    + Received
    
    + INFO: [ADK] 2026-07-30T23:40:22.034Z info-pin-probe
    

    still emits error logs passed, proving the capture harness itself works and the toBe('') assertion is not vacuous.

  2. Mutation A — delete the setupFiles entry from the unit:core project only. suppresses info logs FAILS with the same AssertionError above; still emits error logs passes. Restored.

  3. Mutation B — over-mute: replace the pin with setLogger(null). still emits error logs FAILS with AssertionError: expected '' to contain 'error-pin-probe'; suppresses info logs passes. Restored. This is the control that stops a future "fix" from silencing errors too.

Regression gate. Because this change alters the environment of every test file, the two unit projects CI gates on were run in full and compared against the branch point:

Test files Tests
Base (fix/hermetic-unit-test-env) 175 passed (175) 2414 passed (2414)
With this change 176 passed (176) 2416 passed (2416)

Exactly the one new file and its two tests; nothing else moved.

Noise actually gone. npx vitest run --project unit:core core/test/plugins: [ADK] lines drop from 11 (10 INFO + 1 ERROR) to 1 (the ERROR). The ERROR line is retained by design.

CI is absent on this PR, so it was validated locally instead. .github/workflows/validation.yaml triggers on pull_request: branches: [main], and this PR targets fix/hermetic-unit-test-env (see the stacking note above), so run-tests never fires — only the trivial auto-assign check appears, which is not validation. Everything below was therefore run locally against the exact pushed commit 4abddd7 with a clean working tree:

npm run build          # exit 0
npm run lint           # exit 0
npm run format:check   # exit 0
npx secretlint "**/*"  # exit 0
npm run docs:check     # exit 0
npx vitest run --project unit:core --project unit:dev   # exit 0 -- 176 files, 2416 tests

Other checks, all on the pushed commit:

  • npm run lint — pass (exit 0). npm run format:check — pass. npx secretlint "**/*" — pass. npm run build — pass.
  • npm run ts:check — 308 errors, but the error sets are byte-identical with and without this change and none are in the touched files (CI does not run ts:check).
  • unit:integrations — 1 failure, integrations/test/version_test.ts (expected '1.4.0' to be '1.3.0'), identical with and without this change; a pre-existing rotted version pin already covered by another open PR.
  • integration project — fails on both base and this branch with Hook timed out in the fixture npm install/bundling hooks (build_setup, agent_loader, app_loader, skills/script_js), a known pre-existing flake in this environment. Confirmed non-causal: run three times in each configuration, base flaked too (1/3 failures), and vitest reports this change's setup cost as 142ms against a 40,000ms hook budget.
  • e2e and cross-language were not run locally — they require credentials. Both still receive the same setupFiles entry.

Manual End-to-End (E2E) Tests:
Please provide instructions on how to manually test your changes, including any necessary setup or configuration.

npm install && npm run build

# 1. The regression test passes.
npx vitest run --project unit:core core/test/utils/log_level_pin_test.ts

# 2. The INFO noise is gone; the ERROR line remains.
npx vitest run --project unit:core core/test/plugins 2>&1 | grep '\[ADK\]'

# 3. Revert the fix to see the bug: drop the './tests/setup_log_level.ts'
#    entry from the unit:core project in vitest.config.ts and re-run step 1.
#    'suppresses info logs' fails and step 2 prints 10 INFO lines again.

# 4. Full gate.
npx vitest run --project unit:core --project unit:dev

Checklist

[x] I have read the CONTRIBUTING.md document.
[x] I have performed a self-review of my own code.
[x] I have commented my code, particularly in hard-to-understand areas.
[x] I have added tests that prove my fix is effective or that my feature works.
[x] New and existing unit tests pass locally with my changes.

Amaad Martin added 5 commits July 30, 2026 02:15
Several unit tests read Google Cloud configuration straight out of
process.env, so a developer who has run `gcloud auth application-default
login` or exported GOOGLE_CLOUD_PROJECT sees failures that CI can never
reproduce: GitHub Actions runners export none of these variables.

Wire a setup file into the three unit:* projects that deletes the eight
ambient cloud/credential variables from each worker's environment before
the test module is imported. A plain delete (rather than vi.stubEnv)
survives vi.unstubAllEnvs(), so no test can resurrect the ambient value.

Only the unit:* projects are wired. integration, e2e and cross-language
keep the ambient environment, because that is how a developer supplies
real credentials to them -- scrubbing run-wide via globalSetup would
silently turn the e2e suite into skips.
Two cases, each pinning a distinct failure mode. The first drives
scrubAmbientCloudEnv table-driven off the exported list and is the case
that runs meaningfully in CI. The second asserts the unit worker
environment is clean, which pins the setupFiles wiring in
vitest.config.ts: hermetic_env.ts is side-effect free, so that assertion
only holds when the setup file really ran.
GOOGLE_APPLICATION_CREDENTIALS is not read by ADK source -- it is
consumed by google-auth-library beneath the genai SDK. Saying otherwise
invites a future reader who greps for it to prune the one entry that
points at real credentials.
`tests/global_setup.ts` called `setLogLevel(LogLevel.ERROR)` from a vitest
`globalSetup` module, which runs once in the Vitest main process. Every test
file runs in a separate forked worker with a fresh module graph, and the level
lives in module-level state on `SimpleLogger`, so the pin never reached a
single test. ADK still logged at INFO throughout the suite.

Move the pin to a per-project `setupFiles` module, which vitest evaluates
inside each worker before the test file. Root-level `setupFiles` is not
inherited by inline `projects` entries unless they set `extends: true`, so the
entry is repeated on each project, matching how `alias` is already repeated.

The setup file imports the logger module directly instead of the `@google/adk`
barrel: a setup file is evaluated before the test module, so importing the
public entry point there instantiates the real core module graph before a test
file's hoisted `vi.mock` calls can replace any of it, which breaks mocking in
over a hundred test files.
Asserts what the logger actually writes, since `SimpleLogger.logLevel` is
private and there is no public read accessor: an `info` call produces no
console output while an `error` call still does.

Winston's Console transport writes to the stream held by whatever
`globalThis.console` is at log time, so the helper swaps in a `node:console`
Console bound to an in-memory `Writable`. Spying on `process.stdout.write` or
`console.log` captures nothing, because vitest replaces the global console
with its own instance backed by a private stream.
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