Skip to content

Refactor: deduplicate the winston logger into one level-gated implementation with one process-wide default level - #432

Open
AmaadMartin wants to merge 3 commits into
mainfrom
feat/shared-level-gated-winston-logger
Open

Refactor: deduplicate the winston logger into one level-gated implementation with one process-wide default level#432
AmaadMartin wants to merge 3 commits into
mainfrom
feat/shared-level-gated-winston-logger

Conversation

@AmaadMartin

@AmaadMartin AmaadMartin commented Aug 1, 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):
    N/A — no existing issue.
  2. Or, if no issue exists, describe the change:

Problem: adk-js ships two near-identical winston-backed loggers —
SimpleLogger in core/src/utils/logger.ts and AdkLogger in
dev/src/utils/logger.ts. Both carry the same private logLevel: LogLevel = LogLevel.INFO
field, the same if (this.logLevel > LogLevel.X) return; guard in each of
log/debug/info/warn/error, and the same inverted winston levels map
paired with level: 'error'. The only genuine difference is that AdkLogger
builds its format chain from options while SimpleLogger hardcodes one.

Two consequences:

  1. Every gating fix has to be made twice. There is already a latent bug
    living in both copies: log() does this.logger.log(level.toString(), ...),
    but LogLevel is a numeric enum, so it passes '0'..'3' — none of which
    are keys of the winston levels map. Verified against the pinned
    winston@3.19.0 from this repo's lockfile: with the colorize format in the
    chain, Logger.log(LogLevel.INFO, 'x') does not merely drop the message, it
    throws TypeError: colors[Colorizer.allColors[lookup]] is not a function
    from logform/colorize.js:73. (Before/after transcript below.)
  2. There is no process-wide way to pin the dev logger's level. AdkLogger
    instances are per-object and are constructed at module load
    (dev/src/utils/agent_loader.ts:29) or per construction
    (dev/src/server/adk_api_server.ts, dev/src/cli/cli.ts:200). A harness
    calling the exported setLogLevel(LogLevel.ERROR) from @google/adk reached
    only core's currentLogger; the dev-package loggers kept logging.

Solution: extract one level-gated winston logger into core, parameterised
only by the format options that actually differ, and give it one process-wide
default level that both packages' loggers read at log time.

  • core/src/utils/logger.ts gains WinstonLoggerOptions and
    class WinstonLogger implements Logger, which owns the winston construction
    (levels map, level: 'error', Console transport) and the level gating
    (isEnabled, one predicate used by all five methods).
  • SimpleLogger becomes a preset: class SimpleLogger extends WinstonLogger
    over a module-level DEFAULT_LOGGER_OPTIONS. It stays module-private.
  • A WinstonLogger leaves logLevel unset until setLogLevel() is called
    on that instance, and resolves this.logLevel ?? defaultLogLevel on every log
    call. Resolving at log time (rather than capturing in the constructor) is what
    lets one setLogLevel() reach a logger that was constructed at import time.
  • The exported setLogLevel() writes that module-level defaultLogLevel and
    still forwards to the registry logger, so a caller-supplied custom Logger
    installed via setLogger() keeps working unchanged.
  • dev/src/utils/logger.ts collapses to a single re-export,
    export {WinstonLogger as AdkLogger} from '@google/adk';. The dev-package
    name its three call sites already use is preserved without minting a second
    constructor and prototype for identical behaviour; nothing subclasses it and
    nothing uses instanceof, so it is a drop-in. No file under dev/src imports
    winston any more (grep -rn winston dev/src returns only a doc-comment
    reference).
  • The level-name bug is fixed once, in the shared log(), by deriving the
    winston level name from the enum itself — LogLevel[level].toLowerCase().
    LogLevel is a non-const numeric enum, so its reverse mapping yields exactly
    the four keys of the levels map the constructor already passes to winston;
    no second table has to be kept in agreement with it.
  • AdkApiServer now pins its logger only when the caller supplied a
    logLevel, so a server logger that was never explicitly pinned follows the
    process-wide default. The CLI is unaffected — dev/src/cli/cli.ts always
    passes an explicit logLevel.

Why this shape: WinstonLogger stays in core/src/utils/logger.ts rather
than moving to its own module — splitting it out creates an import cycle with
the LogLevel enum that crashes at module init with a TDZ ReferenceError.
WinstonLogger/WinstonLoggerOptions are exported from core/src/common.ts
because dev consumes @google/adk as a package, so a non-exported symbol is
unreachable from it.

  • ServerOptions.agentLoader is typed as AgentLoaderLikePick<AgentLoader, 'listAgents' | 'getAgentFile'>, the only two methods the server ever calls on
    it — instead of the concrete class. The concrete AgentLoader has private
    fields, which is what forces every test double in the package to launder
    itself through as unknown as; declaring the dependency structurally removes
    that pressure at the root, and the new constructor tests need no cast.

Public API is additive only. WinstonLogger and WinstonLoggerOptions are
added; nothing is removed or renamed. dev/src/utils/logger.ts's
AdkLoggerOptions alias is dropped: once AdkLogger stopped declaring its own
constructor the alias typed nothing, it has zero references in dev/src or
dev/test, and dev/src/index.ts never re-exported the module, so it was
unreachable from outside @google/adk-devtools in the first place. Widening
ServerOptions.agentLoader is not breaking for callers — a real AgentLoader
still satisfies it.

Three intended behaviour changes:

  1. setLogLevel() now also changes the level of built-in loggers in the dev
    package. Previously it touched only core's currentLogger. This is the point
    of the change.
  2. AdkApiServer no longer forces its logger to INFO when options.logLevel
    is omitted. A caller that passes options.logger and omits logLevel now
    keeps its own logger's level instead of having it silently overwritten.
  3. Logger.log(level, ...) now emits at the right winston level instead of
    throwing / dropping the message.

No behaviour change to core's rendered output. Same format chain, same
order, same colorize/label/timestamp semantics — proved byte-for-byte below.

Deliberate scope limits (all called out in the task spec as non-goals, none
of them silent): vitest.config.ts and tests/global_setup.ts are untouched;
the now-unused winston entry in dev/package.json is left in place rather
than churning the lockfile; no setDefaultLogLevel API is added (the existing
setLogLevel is the single source); LogLevel's numeric values are unchanged.

Collision check (required before starting): scanned all 300 open PRs on the
fork. No PR implements this change. Three plausibly adjacent PRs were checked by
file list and none conflict in substance — #349 (vitest.config.ts,
tests/global_setup.ts — deliberately out of scope here), #365
(dev/src/utils/agent_loader.ts only), and #193/#241 (adjacent export lines in
core/src/common.ts). Branched from main, not stacked.

Disclosures:

  • No suppression of any kind is added. No any, no @ts-expect-error, no
    eslint-disable, no coverage pragma, and no as unknown as — the one cast an
    earlier revision of this branch had in the new server tests was removed by
    typing the option as AgentLoaderLike instead. The single remaining
    as unknown as AgentLoader in dev/test/server/adk_api_server_test.ts:238 is
    pre-existing and untouched by this diff; it stays because its stub returns a
    fake AgentFile, and AgentFile has private fields too, so removing it would
    mean growing a second structural type this change does not need.
  • SimpleLogger is deliberately kept as a subclass. It looks behaviourless,
    but it is not: the untouched core/test/utils/logger_test.ts:141 asserts the
    default logger's constructor.name is 'SimpleLogger'. Inlining
    new WinstonLogger(DEFAULT_LOGGER_OPTIONS) at the two construction sites was
    tried and fails that pre-existing test with
    expected 'WinstonLogger' to be 'SimpleLogger'. The class name is observable
    public behaviour here, so the subclass earns its keep; AdkLogger, which
    nothing asserts on, was collapsed to a re-export.
  • The early-return guard in WinstonLogger.error() is unreachable today, because
    LogLevel.ERROR is the maximum level, so isEnabled(ERROR) is always true.
    It is carried over verbatim from both original implementations; removing it
    would make error() the one method that reads as ungated. It is the only
    uncovered branch in the new code (see coverage below).

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.

New: core/test/utils/logger_gating_test.ts (42 tests) and
dev/test/utils/logger_test.ts (19 tests). Each mocks only winston's
createLogger, spreading the real namespace so winston.format and
winston.transports stay real — the format chain is asserted by running the
captured config's format.transform(...), not by stubbing it. A new top-level
describe('AdkApiServer log level') is appended to
dev/test/server/adk_api_server_test.ts; it is a sibling of the existing
describe('AdkWebServer') so it does not inherit that block's server-starting
beforeEach. No existing test was edited, weakened, skipped or deleted; the
pre-existing core/test/utils/logger_test.ts still passes untouched.

Between them the new tests pin: the full 4x4 (threshold x level) gating matrix
through the named methods and through log(), in both packages; that log()
emits at the winston level name rather than the numeric enum value; the INFO
default for an unpinned instance; that the process-wide default reaches an
instance constructed before setLogLevel() was called; that an instance pin
beats the default; message joining; the inverted levels map and level: 'error';
label / uppercased level / timestamp / printFormat wiring, the
timestamp: false case and the default printFormat; and that SimpleLogger's
rendered line is unchanged.

$ npx vitest run --project unit:core --project unit:dev \
    core/test/utils/logger_gating_test.ts core/test/utils/logger_test.ts \
    dev/test/utils/logger_test.ts dev/test/server/adk_api_server_test.ts
 Test Files  4 passed (4)
      Tests  122 passed (122)

Also green on the wider slice that touches the logger API, and on the whole
dev package:

$ npx vitest run --project unit:core core/test/utils/ core/test/plugins/ \
    core/test/models/routed_llm_test.ts core/test/agents/routed_agent_test.ts \
    core/test/memory/vertex_ai_memory_bank_service_test.ts
 Test Files  29 passed (29)
      Tests  443 passed (443)

$ npx vitest run --project unit:dev
 Test Files  1 failed | 14 passed (15)
      Tests  1 failed | 243 passed (244)

The single unit:dev failure is cli_create_test.ts > should handle Vertex AI selection with gcloud defaults. It is pre-existing and unrelated — verified
by checking out the branch base (b390217e) and running that file alone, where
it fails identically.

Static checks: npm run lint, npm run format:check and npm run docs:check
all exit 0. npx tsc --noEmit produces the identical per-file error set before
and after this change (the repo's ts:check has a large pre-existing backlog in
core/test); zero errors in core/src or dev/src.

Coverage. Measured over the two changed modules with the suites above:

File            | % Stmts | % Branch | % Funcs | % Lines | Uncovered Line #s
 core/src/utils |   95.52 |    97.61 |   88.46 |   95.52 |
  logger.ts     |   95.52 |    97.61 |   88.46 |   95.52 | 153-154,230-231,242-243
 dev/src/utils  |     100 |      100 |     100 |     100 |
  logger.ts     |     100 |      100 |     100 |     100 |

dev/src/utils/logger.ts is at 100%. In core/src/utils/logger.ts the three
uncovered spans are: 153-154, the provably-unreachable error() guard described
above; and 230-231 / 242-243, the pre-existing logger.warn / logger.error
facade forwarders, which this change does not touch. Every new line other than
the unreachable guard is exercised.

Proof that each test can fail. Eleven mutations were applied one at a time to
the source and the targeted suites re-run; every one was killed. Reverted after
each. (Re-run in full after the review revisions, against the revised code.)

# Mutation Result
1 this.logLevel ?? defaultLogLevel -> this.logLevel ?? LogLevel.INFO 2 failed — expected [ { level: 'info', …(1) }, …(1) ] to deeply equal [ { level: 'error', …(1) } ] in both packages' "process-wide default" tests
2 capture the default in the field initialiser (private logLevel?: LogLevel = defaultLogLevel) 2 failed — same two tests, same message. This is the design mistake a future refactor is most likely to make.
3 restore this.logger.log(level.toString(), ...) 11 failed — expected [ { level: '1', message: 'named' } ] to deeply equal [ { level: 'info', message: 'named' } ]
4 isEnabled <= -> < 15 failed across both packages — expected [] to deeply equal [ { level: 'debug', …(1) } ]
5 restore this.logger.setLogLevel(options.logLevel ?? LogLevel.INFO) in AdkApiServer 1 failed — expected [ 1 ] to deeply equal []
6 DEFAULT_LOGGER_OPTIONS.label 'ADK' -> 'ADK2' 1 failed — expected '…INFO…: [ADK2] 2026…' to match /^\S*INFO\S*: \[ADK\] \S+ hello world$/
7 drop the uppercase-level format 3 failed — expected '…info…' to contain 'INFO'
8 always push timestamp() regardless of the option 1 failed — expected 'timestamp=2026-…Z' to be 'timestamp=undefined'
9 drop the default printFormat fallback 2 failed — expected 'undefined' to be 'plain'
10 level: 'error' -> level: 'debug' in the winston config 1 failed — expected 'debug' to be 'error'

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

All of the following were run locally on the pushed commit, against the built
packages (npm run build), with no mocks — real winston writing to real
stdout in a real Node process.

1. Install the built packages into a scratch project.

npm run build
mkdir /tmp/adk_logger_e2e && cd /tmp/adk_logger_e2e
printf '{"name":"adk-logger-e2e","private":true,"type":"module"}' > package.json
npm i --no-save <repo>/core <repo>/dev

2. Run a script that exercises the feature end to end — construct an
AdkLogger before touching the level, call log() with the numeric enum,
then setLogLevel(LogLevel.ERROR) from @google/adk, then start a real
AdkApiServer and issue a real fetch to /list-apps:

import {LogLevel, setLogLevel} from '@google/adk';
import {AdkApiServer} from '@google/adk-devtools';
import {AdkLogger} from './node_modules/@google/adk-devtools/dist/esm/utils/logger.js';

const early = new AdkLogger({
  label: 'Early',
  colorize: {level: true},
  timestamp: true,
  printFormat: (i) => `${i.level}: [${i.label}] ${i.timestamp} ${i.message}`,
});
early.log(LogLevel.INFO, 'log-via-enum');
early.info('info-before-mute');
setLogLevel(LogLevel.ERROR);
early.info('info-after-mute-SHOULD-NOT-APPEAR');
early.error('error-after-mute');
const server = new AdkApiServer({agentsDir: process.cwd(), host: '127.0.0.1'});
await server.start();
await fetch(`${server.url}/list-apps`); // expect: no INFO request line
setLogLevel(LogLevel.INFO);
await fetch(`${server.url}/list-apps`); // expect: the INFO request line returns
await server.stop();

Results, run against the branch base (b390217e) and against this branch, with
the packages reinstalled from each build:

===== BEFORE (branch base b390217e) =====
log() threw: TypeError: colors[Colorizer.allColors[lookup]] is not a function
FAIL  log(LogLevel.INFO) does not throw
FAIL  log(LogLevel.INFO) emits a real INFO line
PASS  info() before the mute is emitted
FAIL  info() after the mute is suppressed
PASS  error() after the mute is emitted
FAIL  server request log muted by setLogLevel(ERROR)
FAIL  server request log returns after setLogLevel(INFO)

===== AFTER (this branch) =====
PASS  log(LogLevel.INFO) does not throw
PASS  log(LogLevel.INFO) emits a real INFO line
PASS  info() before the mute is emitted
PASS  info() after the mute is suppressed
PASS  error() after the mute is emitted
PASS  server request log muted by setLogLevel(ERROR)
PASS  server request log returns after setLogLevel(INFO)

3. Rendered-output parity for core's logger. In one process, log the same
message through the reconstructed pre-change SimpleLogger chain and through
the new getLogger(), capture both stdout writes and normalise the timestamp:

old SimpleLogger chain : "\u001b[32mINFO\u001b[39m: [ADK] <TS> hello world"
new SimpleLogger       : "\u001b[32mINFO\u001b[39m: [ADK] <TS> hello world"
byte-identical         : true

4. The dev server's log format is visually unchanged.

$ node dev/dist/esm/cli_entrypoint.js web ./dev/samples --port 8791
$ curl -s http://localhost:8791/list-apps
INFO: [ADK API Server] 2026-08-01T02:47:27.264Z GET /list-apps

and with --verbose the same request still renders identically (the CLI passes
an explicit logLevel, so the conditional pin takes effect). Note dev/src
contains no logger.debug call sites at all, so --verbose emits no extra DEBUG
lines from the dev server itself either before or after this change.

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 3 commits July 31, 2026 19:27
core and dev each carried a near-identical winston-backed Logger: the same
per-instance level field, the same `if (this.logLevel > LogLevel.X) return;`
guard in all five methods, and the same inverted winston levels map. Every
gating fix had to be made twice, and there was no process-wide way to pin the
dev package's level.

Move the winston construction and the gating into a single `WinstonLogger` in
core, parameterised by the format options that actually differ. `SimpleLogger`
becomes a preset over core's existing format chain (byte-identical rendering);
`AdkLogger` becomes an empty subclass, so no file under dev/src imports winston
any more.

A `WinstonLogger` now leaves its level unset until `setLogLevel` is called on
the instance, and resolves `this.logLevel ?? defaultLogLevel` at log time. The
exported `setLogLevel` writes that process-wide default, so one call reaches
loggers other packages constructed at import time, while an explicit per-instance
pin still wins.

Also fixes a latent bug the duplication had copied into both packages:
`log()` passed `level.toString()` ('0'..'3') to winston, which is not a key of
the levels map, so winston dropped the message and wrote "Unknown logger level"
to stderr. It now maps the enum to the winston level name.

AdkApiServer only pins its logger when the caller supplied a logLevel, so a
server logger that was never explicitly pinned follows the process default.
Adds core/test/utils/logger_gating_test.ts and dev/test/utils/logger_test.ts,
each mocking only winston's createLogger so the real format chain is still
exercised, plus two AdkApiServer constructor tests for the conditional level
pin.

Between them they pin the full 4x4 (threshold x level) gating matrix through
both the named methods and log(), that log() emits at the winston level name
rather than the numeric enum value, that the process-wide default reaches an
instance constructed before setLogLevel was called, that an instance pin beats
that default, and that SimpleLogger's rendered line is unchanged.
…stub cast

Review follow-ups, all reducing the change:

- Delete WINSTON_LEVEL_NAMES. It was a second hand-maintained copy of the
  level table that already exists as the `levels` map passed to
  winston.createLogger. LogLevel is a non-const numeric enum, so the reverse
  mapping gives the same four names: LogLevel[level].toLowerCase().

- Collapse AdkLogger from an empty subclass to a re-export of WinstonLogger.
  It added no method, field or override; the subclass only minted a second
  constructor and prototype for the same behaviour. No call site subclasses it
  or uses instanceof, so `export {WinstonLogger as AdkLogger}` is a drop-in.

- Delete the AdkLoggerOptions alias. Once AdkLogger stopped declaring its own
  constructor the alias typed nothing: it has no reference in dev/src or
  dev/test, and dev/src/index.ts never re-exported the module, so it was
  unreachable from outside the package too.

- Type the server's agentLoader option as AgentLoaderLike, the two methods it
  actually calls, instead of the concrete AgentLoader. The concrete class has
  private fields, which is what forced every test double to launder itself
  through `as unknown as`; the new constructor tests now need no cast.

SimpleLogger is deliberately kept. It is not behaviourless: the untouched
core/test/utils/logger_test.ts asserts the default logger's constructor name
is 'SimpleLogger', and inlining new WinstonLogger(DEFAULT_LOGGER_OPTIONS)
fails it with "expected 'WinstonLogger' to be 'SimpleLogger'".
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