Skip to content

Commit e8a3349

Browse files
Copilotmoshloopyashmehrotra
authored
chore: Add controller-runtime logging adapter using commons/logger with level shifting (#26)
* Initial plan * Add controller-runtime logging adapter with level shifting and default warn level - Add logging.go with levelShiftHandler that adapts controller-runtime logs to flanksource/commons/logger, shifting levels down (info→debug, debug→trace, error→warn) via slog.Handler wrapper - Add NewControllerRuntimeLogger() using commons/logger with default warn level - Update manager.go to use the new adapter instead of logr.Discard() - Add comprehensive logging_test.go verifying level shifting, suppression, WithAttrs/WithGroup propagation, and default warn level behavior Co-authored-by: moshloop <1489660+moshloop@users.noreply.github.com> * Replace constant slog level shift with non-linear shiftLevel() mapping slog Debug now correctly maps to commons Trace (slog -5) instead of being shifted by a constant -4 to slog -8. Added TestShiftLevel unit tests for slog level shift, and additional Enabled tests for Debug→Trace mapping. Co-authored-by: moshloop <1489660+moshloop@users.noreply.github.com> * chore: change logging logic * chore: add log rules in comments --------- Co-authored-by: copilot-swe-agent[bot] <198982749+Copilot@users.noreply.github.com> Co-authored-by: moshloop <1489660+moshloop@users.noreply.github.com> Co-authored-by: Yash Mehrotra <yashmehrotra95@gmail.com>
1 parent 94168ad commit e8a3349

4 files changed

Lines changed: 393 additions & 13 deletions

File tree

logging.go

Lines changed: 92 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,92 @@
1+
package kopper
2+
3+
import (
4+
"context"
5+
"log/slog"
6+
7+
"github.com/flanksource/commons/logger"
8+
"github.com/go-logr/logr"
9+
)
10+
11+
// All Error logs are emitted
12+
// When verbosity is set to 2 (-vv) along with property(kopper.logs=true): Warn logs are emitted as well
13+
// When verbosity is set to 4 (-vvvv) : All logs are emitted
14+
15+
var klog = logger.GetLogger("kopper")
16+
17+
func init() {
18+
klog.SetLogLevel(logger.Error)
19+
}
20+
21+
// computeKopperLogLevel determines the log level for the kopper logger.
22+
// Priority: global level >= Trace2 (4) > kopper.logs=true > default (Error).
23+
// The log.level.kopper property is handled separately by the logger infrastructure.
24+
func computeKopperLogLevel(kopperLogsEnabled bool, globalLevel logger.LogLevel) logger.LogLevel {
25+
if globalLevel >= logger.Trace2 {
26+
return globalLevel
27+
}
28+
if kopperLogsEnabled {
29+
return logger.Warn
30+
}
31+
return logger.Error
32+
}
33+
34+
// shiftLevel maps slog levels from controller-runtime conventions to
35+
// flanksource/commons/logger conventions, shifting each level down by
36+
// one semantic step:
37+
//
38+
// slog Error (8) → commons Warn (slog 4)
39+
// slog Warn (4) → commons Info (slog 0)
40+
// slog Info (0) → commons Debug (slog -4)
41+
// slog Debug (-4) & below → commons Trace (slog -5) & below
42+
func shiftLevel(level slog.Level) slog.Level {
43+
switch {
44+
case level >= slog.LevelError:
45+
return slog.LevelWarn
46+
case level >= slog.LevelWarn:
47+
return slog.LevelInfo
48+
case level >= slog.LevelInfo:
49+
return slog.LevelDebug
50+
case level >= slog.LevelDebug:
51+
return logger.SlogTraceLevel
52+
default:
53+
return logger.SlogTraceLevel + (level - slog.LevelDebug)
54+
}
55+
}
56+
57+
// levelShiftHandler wraps an slog.Handler and shifts all log levels down
58+
// so that controller-runtime logs are mapped to appropriate commons/logger levels.
59+
type levelShiftHandler struct {
60+
handler slog.Handler
61+
}
62+
63+
func (h *levelShiftHandler) Enabled(ctx context.Context, level slog.Level) bool {
64+
return h.handler.Enabled(ctx, shiftLevel(level))
65+
}
66+
67+
func (h *levelShiftHandler) Handle(ctx context.Context, record slog.Record) error {
68+
record.Level = shiftLevel(record.Level)
69+
return h.handler.Handle(ctx, record)
70+
}
71+
72+
func (h *levelShiftHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
73+
return &levelShiftHandler{handler: h.handler.WithAttrs(attrs)}
74+
}
75+
76+
func (h *levelShiftHandler) WithGroup(name string) slog.Handler {
77+
return &levelShiftHandler{handler: h.handler.WithGroup(name)}
78+
}
79+
80+
// NewControllerRuntimeLogger creates a logr.Logger for controller-runtime
81+
// that routes logs through flanksource/commons/logger with level shifting.
82+
// The default log level is set to warn, suppressing most controller-runtime
83+
// noise while allowing important messages through.
84+
func NewControllerRuntimeLogger() logr.Logger {
85+
l := logger.GetLogger("controller-runtime")
86+
l.SetLogLevel(logger.Warn)
87+
slogLogger := l.GetSlogLogger()
88+
handler := &levelShiftHandler{
89+
handler: slogLogger.Handler(),
90+
}
91+
return logr.FromSlogHandler(handler)
92+
}

logging_test.go

Lines changed: 283 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,283 @@
1+
package kopper
2+
3+
import (
4+
"bytes"
5+
"context"
6+
"log/slog"
7+
"strings"
8+
"testing"
9+
10+
"github.com/flanksource/commons/logger"
11+
"github.com/go-logr/logr"
12+
)
13+
14+
func TestComputeKopperLogLevel(t *testing.T) {
15+
tests := []struct {
16+
name string
17+
kopperLogsEnabled bool
18+
globalLevel logger.LogLevel
19+
expected logger.LogLevel
20+
}{
21+
{"default: only errors", false, logger.Info, logger.Error},
22+
{"kopper.logs enabled: warn level", true, logger.Info, logger.Warn},
23+
{"global level 4: all logs", false, logger.Trace2, logger.Trace2},
24+
{"global level 4 with kopper.logs: global wins", true, logger.Trace2, logger.Trace2},
25+
{"global level 2 without kopper.logs: still error only", false, logger.Trace, logger.Error},
26+
{"global level 2 with kopper.logs: warn", true, logger.Trace, logger.Warn},
27+
{"global level 5 beyond trace2: passes through", false, logger.Trace3, logger.Trace3},
28+
}
29+
30+
for _, tt := range tests {
31+
t.Run(tt.name, func(t *testing.T) {
32+
result := computeKopperLogLevel(tt.kopperLogsEnabled, tt.globalLevel)
33+
if result != tt.expected {
34+
t.Errorf("computeKopperLogLevel(%v, %v) = %v, want %v",
35+
tt.kopperLogsEnabled, tt.globalLevel, result, tt.expected)
36+
}
37+
})
38+
}
39+
}
40+
41+
func TestShiftLevel(t *testing.T) {
42+
tests := []struct {
43+
name string
44+
input slog.Level
45+
expected slog.Level
46+
}{
47+
{"slog Error maps to commons Warn", slog.LevelError, slog.LevelWarn},
48+
{"slog Warn maps to commons Info", slog.LevelWarn, slog.LevelInfo},
49+
{"slog Info maps to commons Debug", slog.LevelInfo, slog.LevelDebug},
50+
{"slog Debug maps to commons Trace", slog.LevelDebug, logger.SlogTraceLevel},
51+
{"slog V(1) maps to commons Trace", slog.Level(-1), logger.SlogTraceLevel},
52+
{"slog V(2) maps to commons Trace", slog.Level(-2), logger.SlogTraceLevel},
53+
{"slog V(3) maps to commons Trace", slog.Level(-3), logger.SlogTraceLevel},
54+
{"below slog Debug maps to below Trace", slog.Level(-5), logger.SlogTraceLevel - 1},
55+
{"far below slog Debug maps to deep Trace", slog.Level(-6), logger.SlogTraceLevel - 2},
56+
}
57+
58+
for _, tt := range tests {
59+
t.Run(tt.name, func(t *testing.T) {
60+
result := shiftLevel(tt.input)
61+
if result != tt.expected {
62+
t.Errorf("shiftLevel(%d) = %d, want %d", tt.input, result, tt.expected)
63+
}
64+
})
65+
}
66+
}
67+
68+
func TestLevelShiftHandler(t *testing.T) {
69+
tests := []struct {
70+
name string
71+
baseLevel slog.Level
72+
logFunc func(logr.Logger)
73+
expectLogged bool
74+
expectLevel string
75+
}{
76+
{
77+
name: "info shifted to debug, base at debug level",
78+
baseLevel: slog.LevelDebug,
79+
logFunc: func(l logr.Logger) { l.Info("test info message") },
80+
expectLogged: true,
81+
expectLevel: "DEBUG",
82+
},
83+
{
84+
name: "info shifted to debug, base at warn - suppressed",
85+
baseLevel: slog.LevelWarn,
86+
logFunc: func(l logr.Logger) { l.Info("test info message") },
87+
expectLogged: false,
88+
},
89+
{
90+
name: "error shifted to warn, base at warn - logged",
91+
baseLevel: slog.LevelWarn,
92+
logFunc: func(l logr.Logger) { l.Error(nil, "error message") },
93+
expectLogged: true,
94+
expectLevel: "WARN",
95+
},
96+
{
97+
name: "error always logged via logr (bypasses level check)",
98+
baseLevel: slog.LevelError,
99+
logFunc: func(l logr.Logger) { l.Error(nil, "error message") },
100+
expectLogged: true,
101+
expectLevel: "WARN",
102+
},
103+
{
104+
name: "V(1) shifted to trace, base at trace level",
105+
baseLevel: logger.SlogTraceLevel,
106+
logFunc: func(l logr.Logger) { l.V(1).Info("debug message") },
107+
expectLogged: true,
108+
},
109+
{
110+
name: "V(1) shifted to trace, base at warn - suppressed",
111+
baseLevel: slog.LevelWarn,
112+
logFunc: func(l logr.Logger) { l.V(1).Info("debug message") },
113+
expectLogged: false,
114+
},
115+
{
116+
name: "V(1) shifted to trace, base at debug - suppressed",
117+
baseLevel: slog.LevelDebug,
118+
logFunc: func(l logr.Logger) { l.V(1).Info("debug message") },
119+
expectLogged: false,
120+
},
121+
}
122+
123+
for _, tt := range tests {
124+
t.Run(tt.name, func(t *testing.T) {
125+
var buf bytes.Buffer
126+
baseHandler := slog.NewTextHandler(&buf, &slog.HandlerOptions{
127+
Level: tt.baseLevel,
128+
})
129+
handler := &levelShiftHandler{handler: baseHandler}
130+
logger := logr.FromSlogHandler(handler)
131+
132+
tt.logFunc(logger)
133+
134+
logged := buf.Len() > 0
135+
if logged != tt.expectLogged {
136+
t.Errorf("expected logged=%v, got logged=%v, output: %q", tt.expectLogged, logged, buf.String())
137+
}
138+
139+
if tt.expectLogged && tt.expectLevel != "" {
140+
if !strings.Contains(buf.String(), "level="+tt.expectLevel) {
141+
t.Errorf("expected level=%s in output, got: %q", tt.expectLevel, buf.String())
142+
}
143+
}
144+
})
145+
}
146+
}
147+
148+
func TestLevelShiftHandlerEnabled(t *testing.T) {
149+
tests := []struct {
150+
name string
151+
baseLevel slog.Level
152+
testLevel slog.Level
153+
expected bool
154+
}{
155+
{
156+
name: "info enabled when base is debug",
157+
baseLevel: slog.LevelDebug,
158+
testLevel: slog.LevelInfo,
159+
expected: true,
160+
},
161+
{
162+
name: "info disabled when base is warn (info shifts to debug)",
163+
baseLevel: slog.LevelWarn,
164+
testLevel: slog.LevelInfo,
165+
expected: false,
166+
},
167+
{
168+
name: "error enabled when base is warn (error shifts to warn)",
169+
baseLevel: slog.LevelWarn,
170+
testLevel: slog.LevelError,
171+
expected: true,
172+
},
173+
{
174+
name: "error disabled when base is error+1 (error shifts to warn)",
175+
baseLevel: slog.LevelError + 1,
176+
testLevel: slog.LevelError,
177+
expected: false,
178+
},
179+
{
180+
name: "debug enabled when base is trace (debug shifts to trace)",
181+
baseLevel: logger.SlogTraceLevel,
182+
testLevel: slog.LevelDebug,
183+
expected: true,
184+
},
185+
{
186+
name: "debug disabled when base is debug (debug shifts to trace)",
187+
baseLevel: slog.LevelDebug,
188+
testLevel: slog.LevelDebug,
189+
expected: false,
190+
},
191+
}
192+
193+
for _, tt := range tests {
194+
t.Run(tt.name, func(t *testing.T) {
195+
baseHandler := slog.NewTextHandler(&bytes.Buffer{}, &slog.HandlerOptions{
196+
Level: tt.baseLevel,
197+
})
198+
handler := &levelShiftHandler{handler: baseHandler}
199+
200+
result := handler.Enabled(context.Background(), tt.testLevel)
201+
if result != tt.expected {
202+
t.Errorf("Enabled(%v) = %v, want %v (base level: %v, shifted: %v)",
203+
tt.testLevel, result, tt.expected, tt.baseLevel, shiftLevel(tt.testLevel))
204+
}
205+
})
206+
}
207+
}
208+
209+
func TestLevelShiftHandlerWithAttrs(t *testing.T) {
210+
var buf bytes.Buffer
211+
baseHandler := slog.NewTextHandler(&buf, &slog.HandlerOptions{
212+
Level: slog.LevelDebug,
213+
})
214+
handler := &levelShiftHandler{handler: baseHandler}
215+
216+
// WithAttrs should preserve the level shift
217+
attrHandler := handler.WithAttrs([]slog.Attr{slog.String("key", "value")})
218+
logger := logr.FromSlogHandler(attrHandler)
219+
220+
logger.Info("test with attrs")
221+
222+
output := buf.String()
223+
if !strings.Contains(output, "key=value") {
224+
t.Errorf("expected attrs in output, got: %q", output)
225+
}
226+
if !strings.Contains(output, "level=DEBUG") {
227+
t.Errorf("expected level=DEBUG (shifted from info), got: %q", output)
228+
}
229+
}
230+
231+
func TestLevelShiftHandlerWithGroup(t *testing.T) {
232+
var buf bytes.Buffer
233+
baseHandler := slog.NewTextHandler(&buf, &slog.HandlerOptions{
234+
Level: slog.LevelDebug,
235+
})
236+
handler := &levelShiftHandler{handler: baseHandler}
237+
238+
// WithGroup should preserve the level shift
239+
groupHandler := handler.WithGroup("testgroup")
240+
logger := logr.FromSlogHandler(groupHandler)
241+
242+
logger.Info("test with group", "nested", "val")
243+
244+
output := buf.String()
245+
if !strings.Contains(output, "testgroup.nested=val") {
246+
t.Errorf("expected grouped attrs in output, got: %q", output)
247+
}
248+
if !strings.Contains(output, "level=DEBUG") {
249+
t.Errorf("expected level=DEBUG (shifted from info), got: %q", output)
250+
}
251+
}
252+
253+
func TestDefaultWarnLevelSuppression(t *testing.T) {
254+
// Simulate the default warn level behavior:
255+
// With warn level, only controller-runtime errors (shifted to warn) should pass through.
256+
var buf bytes.Buffer
257+
baseHandler := slog.NewTextHandler(&buf, &slog.HandlerOptions{
258+
Level: slog.LevelWarn,
259+
})
260+
handler := &levelShiftHandler{handler: baseHandler}
261+
logger := logr.FromSlogHandler(handler)
262+
263+
// Info should be suppressed (shifted to debug, below warn)
264+
logger.Info("info message")
265+
if buf.Len() > 0 {
266+
t.Errorf("info message should be suppressed at warn level, got: %q", buf.String())
267+
}
268+
269+
// V(1) debug should be suppressed (shifted to trace, below warn)
270+
logger.V(1).Info("debug message")
271+
if buf.Len() > 0 {
272+
t.Errorf("V(1) debug message should be suppressed at warn level, got: %q", buf.String())
273+
}
274+
275+
// Error should be logged (shifted to warn, equals warn)
276+
logger.Error(nil, "error message")
277+
if buf.Len() == 0 {
278+
t.Error("error message should be logged at warn level")
279+
}
280+
if !strings.Contains(buf.String(), "error message") {
281+
t.Errorf("expected error message in output, got: %q", buf.String())
282+
}
283+
}

0 commit comments

Comments
 (0)