Skip to content

Commit be4d221

Browse files
otelcol/grpclog: suppress benign gRPC client-disconnect warnings (#15024)
Fixes #5169 ## Problem When a gRPC client disconnects normally (e.g., a .NET app shutting down its `TracerProvider`), the collector logs spurious WARN messages from the gRPC transport layer: These are expected during graceful client shutdown but appear alarming to operators and pollute production logs. ## Root cause grpc-go is doing the right thing: messages like this are gated behind `LoggerV2.V(2)` in `internal/transport/http2_server.go`, i.e. they are explicitly classified as supplemental verbosity, not severity-level warnings. They should never reach a WARN sink. The bug is in zapgrpc. `zapgrpc.Logger.V` is implemented as `levelEnabler.Enabled(zapcore.Level(level - 1))`, which conflates grpclog's *verbosity* with zap's *severity*. With WARN enabled, `V(2)` returns true, so grpc-go thinks verbosity level 2 is permitted and emits the message — which then gets formatted by zapgrpc as a WARN entry. See [uber-go/zap#1544](uber-go/zap#1544). ## Solution Wrap the installed `grpclog.LoggerV2` with a `fixedVerbosityLogger` whose `V()` compares the requested level against a fixed threshold (default 0) instead of the underlying zap severity enabler. This restores grpclog's intended verbosity gating, so verbose messages stop at grpc-go before formatting rather than being filtered out of the log stream after the fact. The default threshold of `0` matches grpclog when `GRPC_GO_LOG_VERBOSITY_LEVEL` is unset. This approach: - Addresses the root cause (broken `V()` mapping) rather than string-matching specific message contents. - Stops chatty messages at the source, before grpc-go formats them. - Is generic — kills *all* `V(2)+` noise, including future grpc-go additions, not just two cherry-picked patterns. - Leaves severity-level emission (`Info` / `Warning` / `Error`) completely unchanged. - Tiny: ~10 lines of wrapper plus comment. ## Testing - `TestFixedVerbosity` — asserts `V(0)` is enabled and `V(1)`/`V(2)` are not at the default threshold. - `TestSeverityLevelsUnaffected` — direct `Warning("…")` still fires at WARN, confirming the wrapper does not gate severity. - Existing `TestGRPCLogger` cases continue to pass unchanged. --------- Signed-off-by: Sai Kruthi Wusirika <kruthiwusirika@gmail.com>
1 parent f6da47d commit be4d221

4 files changed

Lines changed: 100 additions & 1 deletion

File tree

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,31 @@
1+
# Use this changelog template to create an entry for release notes.
2+
3+
# One of 'breaking', 'deprecation', 'new_component', 'enhancement', 'bug_fix'
4+
change_type: bug_fix
5+
6+
# The name of the component, or a single word describing the area of concern, (e.g. receiver/otlp)
7+
component: pkg/otelcol
8+
9+
# A brief description of the change. Surround your text with quotes ("") if it needs to start with a backtick (`).
10+
note: Stop emitting verbose gRPC transport messages at WARN during normal client disconnect.
11+
12+
# One or more tracking issues or pull requests related to the change
13+
issues: [5169]
14+
15+
# (Optional) One or more lines of additional information to render under the primary note.
16+
# These lines will be padded with 2 spaces and then inserted directly into the document.
17+
# Use pipe (|) for multiline entries.
18+
subtext: |
19+
grpc-go gates chatty per-RPC notices (e.g. "HandleStreams failed to read frame:
20+
connection reset by peer") behind `LoggerV2.V(2)`. zapgrpc.Logger.V conflates
21+
grpclog verbosity with zap severity, so V(2) returns true whenever WARN is
22+
enabled and these messages emit at WARN. Wrap the installed grpclog.LoggerV2
23+
with a corrected V() that compares against a fixed verbosity threshold,
24+
matching grpclog's intended semantics. See uber-go/zap#1544.
25+
26+
# Optional: The change log or logs in which this entry should be included.
27+
# e.g. '[user]' or '[user, api]'
28+
# Include 'user' if the change is relevant to end users.
29+
# Include 'api' if there is a change to a library API.
30+
# Default: '[user]'
31+
change_logs: [user]

.github/workflows/utils/cspell.json

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -260,6 +260,8 @@
260260
"groupbytrace",
261261
"groupbytraceprocessor",
262262
"grpclb",
263+
"grpclog",
264+
"grpclog's",
263265
"guiton",
264266
"healthcheck",
265267
"healthcheckextension",
@@ -295,6 +297,7 @@
295297
"koanf",
296298
"labeldrop",
297299
"ldflags",
300+
"lifecycles",
298301
"limitermiddleware",
299302
"localhostgate",
300303
"loggingexporter",
@@ -533,6 +536,7 @@
533536
"yamlprovider",
534537
"yamls",
535538
"zapcore",
539+
"zapgrpc",
536540
"zipkin",
537541
"zipkinexporter",
538542
"zipkinreceiver",

otelcol/internal/grpclog/logger.go

Lines changed: 21 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,26 @@ import (
1010
"google.golang.org/grpc/grpclog"
1111
)
1212

13+
// fixedVerbosityLogger wraps a grpclog.LoggerV2 and reports verbosity against a
14+
// fixed threshold instead of zap's severity enabler.
15+
//
16+
// zapgrpc.Logger.V(level) is implemented as levelEnabler.Enabled(zapcore.Level(level-1)),
17+
// which conflates grpclog's supplemental verbosity with zap's severity. With WARN
18+
// enabled, V(2) returns true, so grpc-go emits chatty per-RPC messages — including
19+
// transport-layer notices logged on normal client disconnect — at WARN. See
20+
// uber-go/zap#1544.
21+
//
22+
// Comparing against a fixed threshold restores grpclog's intended semantics.
23+
// The default of 0 matches grpclog when GRPC_GO_LOG_VERBOSITY_LEVEL is unset.
24+
type fixedVerbosityLogger struct {
25+
grpclog.LoggerV2
26+
verbosity int
27+
}
28+
29+
func (l *fixedVerbosityLogger) V(level int) bool {
30+
return level <= l.verbosity
31+
}
32+
1333
// SetLogger constructs a zapgrpc.Logger instance, and installs it as grpc logger, cloned from baseLogger with
1434
// exact configuration. The minimum level of gRPC logs is set to WARN should the loglevel of the collector is set to
1535
// INFO to avoid copious logging from grpc framework.
@@ -30,6 +50,6 @@ func SetLogger(baseLogger *zap.Logger) *zapgrpc.Logger {
3050
return c.With([]zapcore.Field{zap.Bool("grpc_log", true)})
3151
}), zap.AddCallerSkip(5)))
3252

33-
grpclog.SetLoggerV2(logger)
53+
grpclog.SetLoggerV2(&fixedVerbosityLogger{LoggerV2: logger})
3454
return logger
3555
}

otelcol/internal/grpclog/logger_test.go

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -83,6 +83,50 @@ func TestGRPCLogger(t *testing.T) {
8383
}
8484
}
8585

86+
func TestFixedVerbosity(t *testing.T) {
87+
// After SetLogger, the installed grpclog.LoggerV2 must report verbosity
88+
// against a fixed threshold (default 0), not against the zap severity
89+
// enabler. With the default threshold, V(0) is enabled and V(1+) is not,
90+
// regardless of the underlying zap level.
91+
logger, err := zap.NewProduction()
92+
require.NoError(t, err)
93+
94+
SetLogger(logger)
95+
96+
v2 := grpclog.V(0)
97+
assert.True(t, v2, "V(0) should be enabled at the default verbosity threshold")
98+
99+
v2 = grpclog.V(1)
100+
assert.False(t, v2, "V(1) should be disabled at the default verbosity threshold")
101+
102+
v2 = grpclog.V(2)
103+
assert.False(t, v2, "V(2) should be disabled at the default verbosity threshold")
104+
}
105+
106+
func TestSeverityLevelsUnaffected(t *testing.T) {
107+
// Severity-level emission must remain unchanged: a direct Warning call
108+
// still fires regardless of the verbosity threshold.
109+
warnLogged := false
110+
hook := zap.Hooks(func(entry zapcore.Entry) error {
111+
if entry.Level == zapcore.WarnLevel {
112+
warnLogged = true
113+
}
114+
return nil
115+
})
116+
117+
cfg := zap.Config{
118+
Level: zap.NewAtomicLevelAt(zapcore.WarnLevel),
119+
Encoding: "console",
120+
}
121+
logger, err := cfg.Build(hook)
122+
require.NoError(t, err)
123+
124+
SetLogger(logger)
125+
component := &mockComponent{logger: grpclog.Component("channelz")}
126+
component.Warning("real warning unrelated to verbosity")
127+
assert.True(t, warnLogged, "severity-level warnings must still be emitted")
128+
}
129+
86130
type mockComponent struct {
87131
logger grpclog.DepthLoggerV2
88132
}

0 commit comments

Comments
 (0)