Skip to content

fix: route snapshot fetcher and gRPC auth logs through the app logger - #1806

Merged
sylr merged 2 commits into
release/v3.0from
fix/unify-snapshot-fetcher-logging
Sep 3, 2026
Merged

fix: route snapshot fetcher and gRPC auth logs through the app logger#1806
sylr merged 2 commits into
release/v3.0from
fix/unify-snapshot-fetcher-logging

Conversation

@sylr

@sylr sylr commented Aug 28, 2026

Copy link
Copy Markdown
Contributor

Problem

Process output mixed two log formats:

time="2026-08-27T16:15:11Z" level=info msg="Downloading snapshot file" path=001424.sst size=33523537
2026-08-27T16:15:12.603Z    INFO    IndexTracker updated in finishReady    {"node-id": 2, ...}

Both call sites use the same logging.Logger interface, but go-libs' logging.FromContext(ctx) silently falls back to a fresh logrus text logger on stderr when the context carries no logger. The snapshot fetcher resolved its logger from the applier's sync context (never has one attached), and gRPC auth failures (logAuthFailure) from the raw request context.

Fix

  • internal/application/ctrl/snapshot_fetcher.go: provider/fetcher take an injected logging.Logger (tagged cmp=snapshot-fetcher) and use logger.WithContext(ctx) instead of FromContext.
  • internal/bootstrap/module.go: pass the app logger into GRPCSnapshotFetcherProvider.
  • internal/adapter/grpc/logger_interceptor.go (new) + server.go: unary/stream interceptors inject the logger into service gRPC request contexts, mirroring the existing HTTP loggerMiddleware. Fixes the same leak for gRPC auth-failure logs.
  • Test fixtures set logger: logging.Testing().

Remaining FromContext callers (HTTP handlers/middleware, e2e testutil) already run under a context with the logger attached.

Validation

  • GOROOT= go build ./..., golangci-lint on touched packages (0 issues), git diff --check
  • go test ./internal/application/ctrl/ ./internal/adapter/grpc/ ./internal/adapter/auth/ ./internal/bootstrap/ — pass
  • scripts/agent-check lint stage reports pre-existing issues in generated *.pb.go files only; nothing in touched files.

@NumaryBot

NumaryBot commented Aug 28, 2026

Copy link
Copy Markdown
Contributor

✅ Approve — automated review

The logger is consistently injected into snapshot-fetcher and gRPC request contexts, with regression tests covering unary, streaming, and snapshot paths. No actionable defects were found.

No findings.

@codecov

codecov Bot commented Aug 28, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 77.08%. Comparing base (b573adf) to head (4f447af).

Additional details and impacted files
@@               Coverage Diff                @@
##           release/v3.0    #1806      +/-   ##
================================================
+ Coverage         77.01%   77.08%   +0.06%     
================================================
  Files               477      478       +1     
  Lines             51141    51155      +14     
================================================
+ Hits              39388    39432      +44     
+ Misses             8318     8291      -27     
+ Partials           3435     3432       -3     
Flag Coverage Δ
e2e 77.08% <100.00%> (+0.06%) ⬆️
scenario 77.08% <100.00%> (+0.06%) ⬆️
unit 77.08% <100.00%> (+0.06%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@shipfox-ai

shipfox-ai Bot commented Aug 28, 2026

Copy link
Copy Markdown

Arbitration — PR #1806: route snapshot fetcher and gRPC auth logs through the app logger

I re-verified the production code and the disputed test claims directly at cf2b9af. Both reviewers converge on the important conclusion: the production implementation is correct — the fetcher logs through the injected logger via f.logger.WithContext(ctx) (snapshot_fetcher.go:79,132,172), the two new interceptors inject the app logger with ContextWithLogger (logger_interceptor.go:16-27) so logging.FromContext in the auth-failure path (grpc_auth.go:272) resolves the app logger instead of go-libs' stderr fallback, the interceptor order is sound (recovery → logger → consistency → logging → errorConversion, server.go:800-812), and every construction site injects a logger (module.go:298, module_restore.go:52, and the test literals). The single substantive issue is a non-blocking test-coverage gap: nothing proves the new wiring actually routes logs to the configured logger, so reverting the fix would leave the suite green. Overall recommendation: approve with comments.

Agreed findings

  • [P2][non-blocking] The logging regression is not behaviorally covered.
    Location: internal/adapter/grpc/logger_interceptor.go:16 (+ stream wiring internal/adapter/grpc/server.go:802,809); internal/application/ctrl/snapshot_fetcher_test.go:157-591.
    Evidence: all 15 fetcher tests only add logger: logging.Testing() (output → io.Discard) and assert nothing about emitted logs. No test in internal/adapter/grpc/*_test.go or internal/adapter/auth/*_test.go references loggerInterceptor/loggerStreamInterceptor/ContextWithLogger, nor asserts an "auth failure" line reaches a buffered app logger; the E2E auth cases assert only gRPC status codes. Both reviewers independently confirmed (and I reproduced the mechanism) that reverting the fetcher to FromContext and dropping the two interceptors compiles and keeps the suite green — i.e. the exact reported mixed-format/stderr regression would return undetected.
    Resolution: add a focused test that drives the real chain with a buffered app logger (logging.NewDefaultLogger(&buf, …)) and asserts both a snapshot fetcher line and a gRPC auth-failure line land in that buffer. The in-repo template already exists: internal/adapter/http/middleware_recoverer_test.go:102 (TestNewHandler_SanitizesPanicEndToEnd), which the PR's own commit message cites as the pattern it mirrors.

Ruled disputes

  1. Number of fetcher tests (14 vs 15). A: "14 fetcher tests." B: "15, not 14 — counting error." Ruling: B is correct. There are 15 TestGRPCSnapshotFetcher_* functions and 15 logger: logging.Testing() literals (snapshot_fetcher_test.go:157,184,222,247,278,307,343,373,402,434,468,488,505,555,591). Immaterial to the finding, but B's count is the accurate one.

  2. "No test sends an auth failure through NewServiceServer." A endorsed this literal wording; B narrowed it to "real auth-failure tests do reach NewServiceServer, but none assert the log destination." Ruling: B's narrowed wording wins. The E2E suite runs the real server via bootstrap.Module()NewServiceServer (module.go:580) and exercises both a unary missing-token failure (GetLedger, auth_test.go:208-213) and a streaming one (ListNumscripts, auth_test.go:310-319). Those requests genuinely traverse the new interceptor chains — but they assert only codes.Unauthenticated, and although the fixture sets Output: GinkgoWriter (auth_test.go:159) it never inspects that output. So the regression class is unguarded, but the correct statement is "no log-destination assertion," not "no server-level auth-failure test."

  3. cmp vs component log-field key as a review finding. A filed it as a Minor nit (fetcher "cmp" at snapshot_fetcher.go:319 vs server "component" at server_snapshot.go:37); B declined to file it, calling it a style nit. Ruling: B is correct — this is not an actionable finding. The keys differ, but each side follows its package's established convention (internal/adapter/grpc uses component: server_bootstrap.go:56, server_cluster.go:91; internal/application/* broadly uses cmp: backup/orchestrator.go:184, events/manager.go:55, etc.), and no code or authoritative doc requires a single cross-package key. Under docs/technical/contributing/ai-review.md ("do not report naming/style preferences that do not violate repository conventions"), it stays a non-actionable observation, not a PR finding. Worth a one-line note only because this PR is about log consistency; not something to hold merge on.

Not in dispute, recorded for completeness: both reviewers agree the HTTP mirror (TestNewHandler_SanitizesPanicEndToEnd) is behaviorally tested and is a ready-made template; Reviewer A correctly withdrew the earlier claim that it was untested.


Reviewed by Claude (claude-opus-4-8) and Codex (gpt-5.6-sol) via Shipfox; arbitrated by Claude.

@sylr

sylr commented Aug 28, 2026

Copy link
Copy Markdown
Contributor Author

Addressed the P2 test-coverage finding in 9e2d295: added TestGRPCSnapshotFetcher_LogsThroughInjectedLogger and TestNewServiceServer_InjectsLoggerIntoRequestContexts. Both drive the real code path with a buffered app logger (the latter through the actual NewServiceServer interceptor chain, unary + stream) and were mutation-checked: each fails when its fix is reverted.

@sylr
sylr force-pushed the fix/unify-snapshot-fetcher-logging branch from 9e2d295 to 35acc30 Compare September 2, 2026 14:06
sylr added 2 commits September 3, 2026 11:30
logging.FromContext falls back to a bare logrus text logger on stderr
when the context carries no logger. The snapshot fetcher resolved its
logger from the applier's sync context, and gRPC auth failures from the
raw request context, so both emitted logrus-formatted lines alongside
the zap-formatted output of the rest of the process.

Inject the app logger into the snapshot fetcher provider and add a
logger-injecting interceptor pair to the service gRPC server, mirroring
the existing HTTP loggerMiddleware.

Rejected: attaching the logger to the root fx context | applier/sync contexts are built from several places; explicit injection matches how every other component receives its logger
Confidence: high
Scope-risk: narrow
Directive: prefer injected loggers over logging.FromContext outside request-scoped handlers whose middleware attaches one
Address the review finding that the logging fix was not behaviorally
covered: reverting the fetcher to logging.FromContext or dropping the
gRPC logger interceptors kept the suite green.

Both tests drive the real code path with a buffered app logger and
assert the emitted lines land there. The gRPC test runs the actual
NewServiceServer chain over an injected listener and exercises a unary
and a streaming RPC. Mutation-checked: each test fails with its fix
reverted.

Confidence: high
Scope-risk: narrow
@sylr
sylr force-pushed the fix/unify-snapshot-fetcher-logging branch from 35acc30 to 4f447af Compare September 3, 2026 09:31

@gfyrag gfyrag left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Reviewed head 4f447af.

The existing HTTP middleware already injects the logger, while the pre-existing gRPC logging interceptor only emitted request logs and did not enrich request contexts. The new unary/stream interceptors correctly cover gRPC auth logging, and explicit injection remains necessary for the background snapshot fetcher. Focused gRPC and snapshot-fetcher tests pass. No blocking findings.

@sylr
sylr merged commit deaa0a5 into release/v3.0 Sep 3, 2026
17 checks passed
@sylr
sylr deleted the fix/unify-snapshot-fetcher-logging branch September 3, 2026 14:42
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Development

Successfully merging this pull request may close these issues.

3 participants