Files
zitadel/backend/v3/instrumentation/slog_test.go
T
5934e07960 fix: recover from request panics (#11713)
# Which Problems Are Solved

Panics may cause a service discruption by unexpectedly closing an
request's connection. Or in the case of gRPC completely killing the
service.

Allthough panics are still individual bugs that need to be solved, this
PR makes sure a panic is gracefully handled and an understandable error
is returned to the client.

# How the Problems Are Solved

- Recover in the middleware interceptors for the 3 API protocols (HTTP,
gRPC, connect).
- HTTP middleware uses formatted responses for:
  - OIDC errors (JSON formatted response)
  - UI (error page rendering)
  - SCIM
- Upon recovery an alert level log is printed (ERROR+4 for stdlib log
handlers)

# Additional Context

- internal observation

---------

Co-authored-by: Livio Spring <[email protected]>
Co-authored-by: Livio Spring <[email protected]>
2026-03-03 11:55:17 +00:00

215 lines
4.8 KiB
Go

package instrumentation
import (
"context"
"errors"
"log/slog"
"testing"
"time"
"github.com/stretchr/testify/assert"
old_logging "github.com/zitadel/logging" //nolint:staticcheck
"github.com/zitadel/sloggcp"
)
func TestLogConfig_SetLegacyConfig(t *testing.T) {
tests := []struct {
name string // description of this test case
lc *old_logging.Config
c *LogConfig
want *LogConfig
}{
{
name: "nil legacy config does not change log config",
lc: nil,
c: &LogConfig{Level: slog.LevelInfo},
want: &LogConfig{Level: slog.LevelInfo},
},
{
name: "legacy config sets log level when format is disabled",
lc: &old_logging.Config{Level: "debug"},
c: &LogConfig{Level: slog.LevelInfo},
want: &LogConfig{Level: slog.LevelDebug},
},
{
name: "legacy config does not change log config when format is not disabled",
lc: &old_logging.Config{Level: "debug"},
c: &LogConfig{Level: slog.LevelInfo, Format: LogFormatJSON},
want: &LogConfig{Level: slog.LevelInfo, Format: LogFormatJSON},
},
{
name: "invalid legacy log level defaults to info",
lc: &old_logging.Config{Level: "invalid"},
c: &LogConfig{Level: slog.LevelDebug},
want: &LogConfig{Level: slog.LevelInfo},
},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
tt.c.SetLegacyConfig(tt.lc)
assert.Equal(t, tt.want, tt.c)
})
}
}
func TestLogConfig_replacer(t *testing.T) {
type args struct {
groups []string
a slog.Attr
}
tests := []struct {
name string // description of this test case
c LogConfig
args args
want slog.Attr
}{
{
name: "empty config does not change attribute",
c: LogConfig{},
args: args{
a: slog.String("key", "value"),
},
want: slog.String("key", "value"),
},
{
name: "masking configured key",
c: LogConfig{
Mask: MaskConfig{
Keys: []string{"sensitive", "foo", "bar"},
Value: "masked",
},
},
args: args{
a: slog.String("sensitive", "value"),
},
want: slog.String("sensitive", "masked"),
},
{
name: "masking configured key in any group",
c: LogConfig{
Mask: MaskConfig{
Keys: []string{"sensitive", "foo", "bar"},
Value: "masked",
},
},
args: args{
groups: []string{"a", "b"},
a: slog.String("sensitive", "value"),
},
want: slog.String("sensitive", "masked"),
},
{
name: "masking configured group",
c: LogConfig{
Mask: MaskConfig{
Keys: []string{"sensitive", "foo", "bar"},
Value: "masked",
},
},
args: args{
groups: []string{"sensitive"},
a: slog.String("unmatched", "value"),
},
want: slog.String("unmatched", "masked"),
},
{
name: "masking configured sub-group",
c: LogConfig{
Mask: MaskConfig{
Keys: []string{"sensitive", "foo", "bar"},
Value: "masked",
},
},
args: args{
groups: []string{"a", "sensitive", "b"},
a: slog.String("unmatched", "value"),
},
want: slog.String("unmatched", "masked"),
},
{
name: "not masking unmatched key",
c: LogConfig{
Mask: MaskConfig{
Keys: []string{"sensitive", "foo", "bar"},
Value: "masked",
},
},
args: args{
a: slog.String("unmatched", "value"),
},
want: slog.String("unmatched", "value"),
},
{
name: "sloggcp replacer",
c: LogConfig{
Format: LogFormatGCP,
},
args: args{
a: slog.Any("level", slog.LevelInfo),
},
want: slog.String(sloggcp.SeverityKey, sloggcp.InfoSeverity),
},
{
name: "errReplacer",
c: LogConfig{
Format: LogFormatGCPErrorReporting,
},
args: args{
a: slog.String("err", "some error"),
},
want: slog.String(sloggcp.ErrorKey, "some error"),
},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
got := tt.c.replacer()(tt.args.groups, tt.args.a)
assert.Equal(t, tt.want, got)
})
}
}
func Test_causeExtractor(t *testing.T) {
background := context.Background()
canceled, cancel := context.WithCancel(background)
cancel()
timedOut, cancel := context.WithTimeout(background, -1)
defer cancel()
canceledCause, cause := context.WithCancelCause(background)
cause(errors.New("oops"))
tests := []struct {
name string // description of this test case
ctx context.Context
want []slog.Attr
}{
{
name: "valid background, no attributes",
ctx: background,
want: nil,
},
{
name: "regular canceled context",
ctx: canceled,
want: nil,
},
{
name: "regular timed out context",
ctx: timedOut,
want: nil,
},
{
name: "canceled context with cause",
ctx: canceledCause,
want: []slog.Attr{
slog.String("cause", "oops"),
},
},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
got := causeExtractor(tt.ctx, time.Time{}, 0, "")
assert.Equal(t, tt.want, got)
})
}
}