httpcaddyfile: Add log_level directive for access logs (#8201)
* httpcaddyfile: Add log_level directive for access logs * Remove AI assistance file * httpcaddyfile: Sort log_level with broader matchers first * caddytest: Cover log_level Caddyfile adaptationpull/7669/head^2
parent
7328273d6f
commit
d293dcfe86
|
|
@ -53,6 +53,7 @@ func init() {
|
|||
RegisterHandlerDirective("skip_log", parseLogSkip)
|
||||
RegisterHandlerDirective("log_skip", parseLogSkip)
|
||||
RegisterHandlerDirective("log_name", parseLogName)
|
||||
RegisterHandlerDirective("log_level", parseLogLevel)
|
||||
}
|
||||
|
||||
// parseBind parses the bind directive. Syntax:
|
||||
|
|
@ -1253,3 +1254,25 @@ func parseLogName(h Helper) (caddyhttp.MiddlewareHandler, error) {
|
|||
caddyhttp.AccessLoggerNameVarKey: h.RemainingArgs(),
|
||||
}, nil
|
||||
}
|
||||
|
||||
// parseLogLevel parses the log_level directive. Syntax:
|
||||
//
|
||||
// log_level [<matcher>] <level>
|
||||
//
|
||||
// The level overrides the access log severity for matching requests.
|
||||
// Supported levels are DEBUG, INFO, WARN, and ERROR (case-insensitive).
|
||||
func parseLogLevel(h Helper) (caddyhttp.MiddlewareHandler, error) {
|
||||
h.Next() // consume directive name
|
||||
args := h.RemainingArgs()
|
||||
if len(args) != 1 {
|
||||
return nil, h.ArgErr()
|
||||
}
|
||||
if h.NextBlock(0) {
|
||||
return nil, h.Err("log_level directive does not accept blocks")
|
||||
}
|
||||
level, err := zapcore.ParseLevel(args[0])
|
||||
if err != nil || level < zapcore.DebugLevel || level > zapcore.ErrorLevel {
|
||||
return nil, h.Errf("invalid log level %q: expected DEBUG, INFO, WARN, or ERROR", args[0])
|
||||
}
|
||||
return caddyhttp.VarsMiddleware{caddyhttp.LogLevelVar: level.String()}, nil
|
||||
}
|
||||
|
|
|
|||
|
|
@ -1,6 +1,7 @@
|
|||
package httpcaddyfile
|
||||
|
||||
import (
|
||||
"encoding/json"
|
||||
"strings"
|
||||
"testing"
|
||||
|
||||
|
|
@ -409,3 +410,102 @@ func TestNestedImport(t *testing.T) {
|
|||
}
|
||||
}
|
||||
}
|
||||
|
||||
func TestLogLevelDirectiveSyntax(t *testing.T) {
|
||||
for _, tc := range []struct {
|
||||
directive string
|
||||
wantError bool
|
||||
}{
|
||||
{"log_level DEBUG", false}, {"log_level info", false},
|
||||
{"log_level WARN", false}, {"log_level ERROR", false},
|
||||
{"log_level /warnings WARN", false},
|
||||
{"log_level", true}, {"log_level INFO WARN", true},
|
||||
{"log_level invalid", true}, {"log_level DPANIC", true},
|
||||
{"log_level PANIC", true}, {"log_level FATAL", true},
|
||||
{"log_level WARN {\n foo\n}", true},
|
||||
} {
|
||||
t.Run(tc.directive, func(t *testing.T) {
|
||||
adapter := caddyfile.Adapter{ServerType: ServerType{}}
|
||||
result, _, err := adapter.Adapt([]byte(":8080 {\n"+tc.directive+"\n}"), nil)
|
||||
if tc.wantError {
|
||||
if err == nil {
|
||||
t.Fatal("expected error")
|
||||
}
|
||||
return
|
||||
}
|
||||
if err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
var config struct {
|
||||
Apps struct {
|
||||
HTTP struct {
|
||||
Servers map[string]struct {
|
||||
Routes []struct {
|
||||
Match []map[string]any
|
||||
Handle []struct {
|
||||
Handler string
|
||||
Level string `json:"log_level"`
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
if err := json.Unmarshal(result, &config); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
routes := config.Apps.HTTP.Servers["srv0"].Routes
|
||||
if len(routes) != 1 || len(routes[0].Handle) != 1 {
|
||||
t.Fatalf("unexpected routes: %s", result)
|
||||
}
|
||||
handler := routes[0].Handle[0]
|
||||
args := strings.Fields(tc.directive)
|
||||
if handler.Handler != "vars" || handler.Level != strings.ToLower(args[len(args)-1]) {
|
||||
t.Fatalf("unexpected handler: %s", result)
|
||||
}
|
||||
if strings.Contains(tc.directive, "/warnings") && len(routes[0].Match) != 1 {
|
||||
t.Fatalf("missing matcher: %s", result)
|
||||
}
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
func TestLogLevelDirectiveOrder(t *testing.T) {
|
||||
for _, input := range []string{
|
||||
"log_level /api/private/* ERROR\nlog_level /api/* DEBUG\nlog_level INFO",
|
||||
"log_level INFO\nlog_level /api/* DEBUG\nlog_level /api/private/* ERROR",
|
||||
} {
|
||||
t.Run(input, func(t *testing.T) {
|
||||
adapter := caddyfile.Adapter{ServerType: ServerType{}}
|
||||
result, _, err := adapter.Adapt([]byte(":8080 {\n"+input+"\n}"), nil)
|
||||
if err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
var config struct {
|
||||
Apps struct {
|
||||
HTTP struct {
|
||||
Servers map[string]struct {
|
||||
Routes []struct {
|
||||
Handle []struct {
|
||||
Level string `json:"log_level"`
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
if err := json.Unmarshal(result, &config); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
var levels []string
|
||||
for _, route := range config.Apps.HTTP.Servers["srv0"].Routes {
|
||||
for _, handler := range route.Handle {
|
||||
levels = append(levels, handler.Level)
|
||||
}
|
||||
}
|
||||
if got := strings.Join(levels, ","); got != "info,debug,error" {
|
||||
t.Fatalf("expected broadest log_level first, got %q: %s", got, result)
|
||||
}
|
||||
})
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -56,6 +56,7 @@ var defaultDirectiveOrder = []string{
|
|||
"skip_log", // TODO: deprecated, renamed to log_skip
|
||||
"log_skip",
|
||||
"log_name",
|
||||
"log_level",
|
||||
|
||||
"header",
|
||||
"copy_response_headers", // only in reverse_proxy's handle_response
|
||||
|
|
@ -470,7 +471,7 @@ func sortRoutes(routes []ConfigValue, order []string) {
|
|||
// that the least-specific matcher is first, allowing the last
|
||||
// matching one to win; we swap i and j instead of using !,
|
||||
// so matchers that can't be compared keep their order
|
||||
if iDir == "vars" {
|
||||
if iDir == "vars" || iDir == "log_level" {
|
||||
i, j = j, i
|
||||
}
|
||||
|
||||
|
|
@ -544,7 +545,7 @@ func sortRoutes(routes []ConfigValue, order []string) {
|
|||
return len(iRoute.MatcherSetsRaw) > 0 && len(jRoute.MatcherSetsRaw) == 0
|
||||
}()
|
||||
|
||||
// most-specific matcher first (or last for vars, see above)
|
||||
// most-specific matcher first (or last for vars and log_level, see above)
|
||||
return sortByPath
|
||||
})
|
||||
}
|
||||
|
|
|
|||
|
|
@ -0,0 +1,42 @@
|
|||
:80
|
||||
|
||||
log_level debug
|
||||
log_level INFO
|
||||
log_level warn
|
||||
log_level ERROR
|
||||
----------
|
||||
{
|
||||
"apps": {
|
||||
"http": {
|
||||
"servers": {
|
||||
"srv0": {
|
||||
"listen": [
|
||||
":80"
|
||||
],
|
||||
"routes": [
|
||||
{
|
||||
"handle": [
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "debug"
|
||||
},
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "info"
|
||||
},
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "warn"
|
||||
},
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "error"
|
||||
}
|
||||
]
|
||||
}
|
||||
]
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
@ -0,0 +1,7 @@
|
|||
:80
|
||||
|
||||
log_level WARN {
|
||||
foo
|
||||
}
|
||||
----------
|
||||
log_level directive does not accept blocks
|
||||
|
|
@ -0,0 +1,5 @@
|
|||
:80
|
||||
|
||||
log_level FATAL
|
||||
----------
|
||||
invalid log level "FATAL": expected DEBUG, INFO, WARN, or ERROR
|
||||
|
|
@ -0,0 +1,5 @@
|
|||
:80
|
||||
|
||||
log_level INVALID
|
||||
----------
|
||||
invalid log level "INVALID": expected DEBUG, INFO, WARN, or ERROR
|
||||
|
|
@ -0,0 +1,63 @@
|
|||
:80
|
||||
|
||||
@first header X-Test a
|
||||
@second header X-Test a
|
||||
@third header X-Other b
|
||||
|
||||
log_level @first INFO
|
||||
log_level @second WARN
|
||||
log_level @third ERROR
|
||||
----------
|
||||
{
|
||||
"apps": {
|
||||
"http": {
|
||||
"servers": {
|
||||
"srv0": {
|
||||
"listen": [
|
||||
":80"
|
||||
],
|
||||
"routes": [
|
||||
{
|
||||
"match": [
|
||||
{
|
||||
"header": {
|
||||
"X-Test": [
|
||||
"a"
|
||||
]
|
||||
}
|
||||
}
|
||||
],
|
||||
"handle": [
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "info"
|
||||
},
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "warn"
|
||||
}
|
||||
]
|
||||
},
|
||||
{
|
||||
"match": [
|
||||
{
|
||||
"header": {
|
||||
"X-Other": [
|
||||
"b"
|
||||
]
|
||||
}
|
||||
}
|
||||
],
|
||||
"handle": [
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "error"
|
||||
}
|
||||
]
|
||||
}
|
||||
]
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
@ -0,0 +1,75 @@
|
|||
:80
|
||||
|
||||
log_level /foobar ERROR
|
||||
log_level /foo WARN
|
||||
log_level /foo* DEBUG
|
||||
log_level INFO
|
||||
----------
|
||||
{
|
||||
"apps": {
|
||||
"http": {
|
||||
"servers": {
|
||||
"srv0": {
|
||||
"listen": [
|
||||
":80"
|
||||
],
|
||||
"routes": [
|
||||
{
|
||||
"handle": [
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "info"
|
||||
}
|
||||
]
|
||||
},
|
||||
{
|
||||
"match": [
|
||||
{
|
||||
"path": [
|
||||
"/foo*"
|
||||
]
|
||||
}
|
||||
],
|
||||
"handle": [
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "debug"
|
||||
}
|
||||
]
|
||||
},
|
||||
{
|
||||
"match": [
|
||||
{
|
||||
"path": [
|
||||
"/foo"
|
||||
]
|
||||
}
|
||||
],
|
||||
"handle": [
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "warn"
|
||||
}
|
||||
]
|
||||
},
|
||||
{
|
||||
"match": [
|
||||
{
|
||||
"path": [
|
||||
"/foobar"
|
||||
]
|
||||
}
|
||||
],
|
||||
"handle": [
|
||||
{
|
||||
"handler": "vars",
|
||||
"log_level": "error"
|
||||
}
|
||||
]
|
||||
}
|
||||
]
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
@ -312,6 +312,10 @@ const (
|
|||
// should be omitted from the access logs
|
||||
LogSkipVar string = "log_skip"
|
||||
|
||||
// LogLevelVar is the request variable used to override access log severity.
|
||||
// Supported string values are DEBUG, INFO, WARN, and ERROR (case-insensitive).
|
||||
LogLevelVar string = "log_level"
|
||||
|
||||
// For adding additional fields to the access logs
|
||||
ExtraLogFieldsCtxKey caddy.CtxKey = "extra_log_fields"
|
||||
|
||||
|
|
|
|||
|
|
@ -1259,6 +1259,11 @@ func (s *Server) logRequest(
|
|||
if status >= 500 {
|
||||
logLevel = zapcore.ErrorLevel
|
||||
}
|
||||
if levelName, ok := GetVar(ctx, LogLevelVar).(string); ok {
|
||||
if level, err := zapcore.ParseLevel(levelName); err == nil && level >= zapcore.DebugLevel && level <= zapcore.ErrorLevel {
|
||||
logLevel = level
|
||||
}
|
||||
}
|
||||
|
||||
var fields []zapcore.Field
|
||||
for _, logger := range loggers {
|
||||
|
|
|
|||
|
|
@ -21,6 +21,7 @@ import (
|
|||
"github.com/stretchr/testify/require"
|
||||
"go.uber.org/zap"
|
||||
"go.uber.org/zap/zapcore"
|
||||
"go.uber.org/zap/zaptest/observer"
|
||||
)
|
||||
|
||||
type syncBuffer struct {
|
||||
|
|
@ -1569,3 +1570,43 @@ func TestServer_ServeHTTP_IdleTimeouts(t *testing.T) {
|
|||
})
|
||||
}
|
||||
}
|
||||
|
||||
func TestServerLogLevel(t *testing.T) {
|
||||
for _, tc := range []struct {
|
||||
name string
|
||||
level any
|
||||
status int
|
||||
minimum zapcore.Level
|
||||
want zapcore.Level
|
||||
skip bool
|
||||
count int
|
||||
}{
|
||||
{"default info", nil, 200, zapcore.DebugLevel, zapcore.InfoLevel, false, 1},
|
||||
{"default error", nil, 500, zapcore.DebugLevel, zapcore.ErrorLevel, false, 1},
|
||||
{"debug", "debug", 200, zapcore.DebugLevel, zapcore.DebugLevel, false, 1},
|
||||
{"warn", "WARN", 200, zapcore.DebugLevel, zapcore.WarnLevel, false, 1},
|
||||
{"error", "ERROR", 200, zapcore.DebugLevel, zapcore.ErrorLevel, false, 1},
|
||||
{"override error", "INFO", 500, zapcore.DebugLevel, zapcore.InfoLevel, false, 1},
|
||||
{"invalid", "invalid", 500, zapcore.DebugLevel, zapcore.ErrorLevel, false, 1},
|
||||
{"unsafe level", "FATAL", 200, zapcore.DebugLevel, zapcore.InfoLevel, false, 1},
|
||||
{"wrong type", 2, 200, zapcore.DebugLevel, zapcore.InfoLevel, false, 1},
|
||||
{"filtered", "INFO", 200, zapcore.WarnLevel, zapcore.InfoLevel, false, 0},
|
||||
{"promoted", "WARN", 200, zapcore.WarnLevel, zapcore.WarnLevel, false, 1},
|
||||
{"skipped", "ERROR", 200, zapcore.DebugLevel, zapcore.ErrorLevel, true, 0},
|
||||
} {
|
||||
t.Run(tc.name, func(t *testing.T) {
|
||||
core, logs := observer.New(tc.minimum)
|
||||
ctx := context.WithValue(context.Background(), ExtraLogFieldsCtxKey, new(ExtraLogFields))
|
||||
ctx = context.WithValue(ctx, VarsCtxKey, map[string]any{LogLevelVar: tc.level, LogSkipVar: tc.skip})
|
||||
req := httptest.NewRequest(http.MethodGet, "/", nil).WithContext(ctx)
|
||||
rec := NewResponseRecorder(httptest.NewRecorder(), nil, nil)
|
||||
rec.WriteHeader(tc.status)
|
||||
duration := time.Millisecond
|
||||
(&Server{}).logRequest(zap.New(core), req, rec, &duration, nil, NewTestReplacer(req), nil, false)
|
||||
require.Equal(t, tc.count, logs.Len())
|
||||
if tc.count > 0 {
|
||||
assert.Equal(t, tc.want, logs.All()[0].Level)
|
||||
}
|
||||
})
|
||||
}
|
||||
}
|
||||
|
|
|
|||
Loading…
Reference in New Issue