fix: improve access logs

router-tests/testenv/testenv.go

@@ -443,14 +443,14 @@ func CreateTestSupervisorEnv(t testing.TB, cfg *Config) (*Environment, error) {
 	if oc := cfg.LogObservation; oc.Enabled {
 		var zCore zapcore.Core
 		zCore, logObserver = observer.New(oc.LogLevel)
-		cfg.Logger = logging.NewZapLoggerWithCore(zCore, true)
+		cfg.Logger = logging.NewZapLoggerWithCore(zCore, true, true)
 	} else {
 		ec := zap.NewProductionEncoderConfig()
 		ec.EncodeDuration = zapcore.SecondsDurationEncoder
 		ec.TimeKey = "time"
 
 		syncer := zapcore.AddSync(os.Stderr)
-		cfg.Logger = logging.NewZapLogger(syncer, false, true, zapcore.ErrorLevel)
+		cfg.Logger = logging.NewZapLogger(syncer, false, true, true, zapcore.ErrorLevel)
 	}
 
 	if cfg.AccessLogger == nil {
@@ -870,14 +870,14 @@ func CreateTestEnv(t testing.TB, cfg *Config) (*Environment, error) {
 	if oc := cfg.LogObservation; oc.Enabled {
 		var zCore zapcore.Core
 		zCore, logObserver = observer.New(oc.LogLevel)
-		cfg.Logger = logging.NewZapLoggerWithCore(zCore, true)
+		cfg.Logger = logging.NewZapLoggerWithCore(zCore, true, true)
 	} else {
 		ec := zap.NewProductionEncoderConfig()
 		ec.EncodeDuration = zapcore.SecondsDurationEncoder
 		ec.TimeKey = "time"
 
 		syncer := zapcore.AddSync(os.Stderr)
-		cfg.Logger = logging.NewZapLogger(syncer, false, true, zapcore.ErrorLevel)
+		cfg.Logger = logging.NewZapLogger(syncer, false, true, true, zapcore.ErrorLevel)
 	}
 
 	if cfg.AccessLogger == nil {

router/cmd/main.go

@@ -90,7 +90,7 @@ func Main() {
 
 	logLevelAtomic := zap.NewAtomicLevelAt(result.Config.LogLevel)
 
-	baseLogger := logging.New(!result.Config.JSONLog, result.Config.DevelopmentMode, logLevelAtomic).
+	baseLogger := logging.New(!result.Config.JSONLog, result.Config.DevelopmentMode, result.Config.AccessLogs.AddStacktrace, logLevelAtomic).
 		With(
 			zap.String("service", "@wundergraph/router"),
 			zap.String("service_version", core.Version),

router/cmd/plan_generator.go

@@ -80,7 +80,7 @@ func PlanGenerator(args []string) {
 		log.Fatalf("Could not parse log level: %s", err)
 	}
 
-	logger := logging.New(false, false, logLevel).
+	logger := logging.New(false, false, true, logLevel).
 		With(
 			zap.String("service", "@wundergraph/query-plan"),
 			zap.String("service_version", core.Version),

router/core/engine_loader_hooks.go

@@ -220,7 +220,12 @@ func (f *engineLoaderHooks) OnFinished(ctx context.Context, ds resolve.DataSourc
 				path = responseInfo.Request.URL.Path
 			}
 		}
-		f.accessLogger.Info(path, fields)
+
+		if responseInfo.Err != nil {
+			f.accessLogger.Error(path, fields)
+		} else {
+			f.accessLogger.Info(path, fields)
+		}
 	}
 
 	if responseInfo.Err != nil {

router/core/graph_server.go

@@ -1075,6 +1075,7 @@ func (s *graphServer) buildGraphMux(
 			requestlogger.WithFields(baseLogFields...),
 			requestlogger.WithAttributes(accessLogAttributes),
 			requestlogger.WithExprAttributes(exprAttributes),
+			requestlogger.WithLogLevelHandler(LogLevelHandler),
 			requestlogger.WithFieldsHandler(RouterAccessLogsFieldHandler),
 			requestlogger.WithIgnoreQueryParamsList(s.accessLogsConfig.IgnoreQueryParamsList),
 		}

router/core/request_context_fields.go

@@ -291,3 +291,20 @@ func getCustomDynamicAttributeValue(
 
 	return ""
 }
+
+func LogLevelHandler(r *http.Request) zapcore.Level {
+	if r == nil {
+		return zapcore.InfoLevel
+	}
+
+	reqContext := getRequestContext(r.Context())
+	if reqContext == nil {
+		return zapcore.InfoLevel
+	}
+
+	if reqContext.error != nil {
+		return zapcore.ErrorLevel
+	}
+
+	return zapcore.InfoLevel
+}

router/core/supervisor_instance.go

@@ -3,9 +3,6 @@ package core
 import (
 	"context"
 	"fmt"
-	"net/http"
-	"os"
-
 	"github.com/KimMachineGun/automemlimit/memlimit"
 	"github.com/dustin/go-humanize"
 	"github.com/wundergraph/cosmo/router/pkg/authentication"
@@ -15,6 +12,10 @@ import (
 	"github.com/wundergraph/cosmo/router/pkg/logging"
 	"go.uber.org/automaxprocs/maxprocs"
 	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	"net/http"
+	"os"
+	"strings"
 )
 
 // newRouter creates a new router instance.
@@ -73,6 +74,15 @@ func newRouter(ctx context.Context, params RouterResources, additionalOptions ..
 			SubgraphAttributes:    cfg.AccessLogs.Subgraphs.Fields,
 		}
 
+		var level zapcore.Level
+		if cfg.AccessLogs.Level == "" {
+			level = zapcore.InfoLevel
+		} else {
+			if err := level.Set(strings.ToUpper(cfg.AccessLogs.Level)); err != nil {
+				return nil, fmt.Errorf("could not parse log level: %w for access logs", err)
+			}
+		}
+
 		if cfg.AccessLogs.Output.File.Enabled {
 			f, err := logging.NewLogFile(cfg.AccessLogs.Output.File.Path, os.FileMode(cfg.AccessLogs.Output.File.Mode))
 			if err != nil {
@@ -84,15 +94,16 @@ func newRouter(ctx context.Context, params RouterResources, additionalOptions ..
 					BufferSize:    int(cfg.AccessLogs.Buffer.Size.Uint64()),
 					FlushInterval: cfg.AccessLogs.Buffer.FlushInterval,
 					Development:   cfg.DevelopmentMode,
-					Level:         zap.InfoLevel,
+					Level:         level,
+					StackTrace:    cfg.AccessLogs.AddStacktrace,
 					Pretty:        !cfg.JSONLog,
 				})
 				if err != nil {
 					return nil, fmt.Errorf("could not create buffered logger: %w", err)
 				}
 				c.Logger = bl.Logger
 			} else {
-				c.Logger = logging.NewZapAccessLogger(f, cfg.DevelopmentMode, !cfg.JSONLog)
+				c.Logger = logging.NewZapAccessLogger(f, level, cfg.DevelopmentMode, !cfg.JSONLog, cfg.AccessLogs.AddStacktrace)
 			}
 		} else if cfg.AccessLogs.Output.Stdout.Enabled {
 			if cfg.AccessLogs.Buffer.Enabled {
@@ -101,15 +112,16 @@ func newRouter(ctx context.Context, params RouterResources, additionalOptions ..
 					BufferSize:    int(cfg.AccessLogs.Buffer.Size.Uint64()),
 					FlushInterval: cfg.AccessLogs.Buffer.FlushInterval,
 					Development:   cfg.DevelopmentMode,
-					Level:         zap.InfoLevel,
+					Level:         level,
+					StackTrace:    cfg.AccessLogs.AddStacktrace,
 					Pretty:        !cfg.JSONLog,
 				})
 				if err != nil {
 					return nil, fmt.Errorf("could not create buffered logger: %w", err)
 				}
 				c.Logger = bl.Logger
 			} else {
-				c.Logger = logging.NewZapAccessLogger(os.Stdout, cfg.DevelopmentMode, !cfg.JSONLog)
+				c.Logger = logging.NewZapAccessLogger(os.Stdout, level, cfg.DevelopmentMode, !cfg.JSONLog, cfg.AccessLogs.AddStacktrace)
 			}
 		}
 

router/internal/requestlogger/requestlogger.go

@@ -50,9 +50,11 @@ const (
 )
 
 type handler struct {
-	accessLogger *accessLogger
-	handler      http.Handler
-	logger       *zap.Logger
+	accessLogger    *accessLogger
+	handler         http.Handler
+	logger          *zap.Logger
+	panicLogger     *zap.Logger
+	logLevelHandler func(r *http.Request) zapcore.Level
 }
 
 func parseOptions(r *handler, opts ...Option) http.Handler {
@@ -110,6 +112,12 @@ func WithDefaultOptions() Option {
 	}
 }
 
+func WithLogLevelHandler(fn func(r *http.Request) zapcore.Level) Option {
+	return func(r *handler) {
+		r.logLevelHandler = fn
+	}
+}
+
 func WithIgnoreQueryParamsList(ignoreList []string) Option {
 	return func(r *handler) {
 		r.accessLogger.ignoreQueryParamsList = ignoreList
@@ -118,9 +126,11 @@ func WithIgnoreQueryParamsList(ignoreList []string) Option {
 
 func New(logger *zap.Logger, opts ...Option) func(h http.Handler) http.Handler {
 	return func(h http.Handler) http.Handler {
+		newLogger := logger.With(zap.String("log_type", "request"))
 		r := &handler{
 			handler:      h,
-			logger:       logger.With(zap.String("log_type", "request")),
+			logger:       newLogger,
+			panicLogger:  newLogger.WithOptions(zap.AddStacktrace(zapcore.ErrorLevel)),
 			accessLogger: &accessLogger{},
 		}
 		return parseOptions(r, opts...)
@@ -162,9 +172,9 @@ func (h *handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 			if brokenPipe {
 				fields = append(fields, zap.Bool("broken_pipe", brokenPipe))
 				// Avoid logging the stack trace for broken pipe errors
-				h.logger.WithOptions(zap.AddStacktrace(zapcore.PanicLevel)).Error(path, fields...)
+				h.panicLogger.WithOptions(zap.AddStacktrace(zapcore.PanicLevel)).Error(path, fields...)
 			} else {
-				h.logger.Error("[Recovery from panic]", fields...)
+				h.panicLogger.Error("[Recovery from panic]", fields...)
 			}
 
 			// Dpanic will panic already in development but in production it will log the error and continue
@@ -188,7 +198,12 @@ func (h *handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		resFields = append(resFields, h.accessLogger.fieldsHandler(h.logger, h.accessLogger.attributes, h.accessLogger.exprAttributes, nil, r, nil, nil)...)
 	}
 
-	h.logger.Info(path, append(fields, resFields...)...)
+	logLevel := zapcore.InfoLevel
+	if h.logLevelHandler != nil {
+		logLevel = h.logLevelHandler(r)
+	}
+
+	h.logger.Log(logLevel, path, append(fields, resFields...)...)
 }
 
 func (al *accessLogger) getRequestFields(r *http.Request, logger *zap.Logger) []zapcore.Field {

router/internal/requestlogger/subgraphlogger.go

@@ -67,3 +67,7 @@ func (h *SubgraphAccessLogger) RequestFields(respInfo *resolve.ResponseInfo, ove
 func (h *SubgraphAccessLogger) Info(message string, fields []zap.Field) {
 	h.logger.Info(message, fields...)
 }
+
+func (h *SubgraphAccessLogger) Error(message string, fields []zap.Field) {
+	h.logger.Error(message, fields...)
+}

router/internal/requestlogger/subgraphlogger_test.go

@@ -21,7 +21,7 @@ func TestSubgraphAccessLogger(t *testing.T) {
 	t.Run("writes correct request log", func(t *testing.T) {
 		var zCore zapcore.Core
 		zCore, logObserver := observer.New(zapcore.InfoLevel)
-		l := logging.NewZapLoggerWithCore(zCore, true)
+		l := logging.NewZapLoggerWithCore(zCore, true, true)
 
 		subgraphLogger := requestlogger.NewSubgraphAccessLogger(l, requestlogger.SubgraphOptions{})
 		req, err := http.NewRequest("POST", "http://localhost:3002/graphql", nil)
@@ -49,7 +49,7 @@ func TestSubgraphAccessLogger(t *testing.T) {
 	t.Run("Should include IP as custom attribute if requested", func(t *testing.T) {
 		var zCore zapcore.Core
 		zCore, logObserver := observer.New(zapcore.InfoLevel)
-		l := logging.NewZapLoggerWithCore(zCore, true)
+		l := logging.NewZapLoggerWithCore(zCore, true, true)
 
 		subgraphLogger := requestlogger.NewSubgraphAccessLogger(l, requestlogger.SubgraphOptions{})
 		req, err := http.NewRequest("POST", "http://localhost:3002/graphql", nil)
@@ -78,7 +78,7 @@ func TestSubgraphAccessLogger(t *testing.T) {
 	t.Run("Should redact client IP and add as a custom attribute", func(t *testing.T) {
 		var zCore zapcore.Core
 		zCore, logObserver := observer.New(zapcore.InfoLevel)
-		l := logging.NewZapLoggerWithCore(zCore, true)
+		l := logging.NewZapLoggerWithCore(zCore, true, true)
 
 		subgraphLogger := requestlogger.NewSubgraphAccessLogger(l, requestlogger.SubgraphOptions{
 			IPAnonymizationConfig: &requestlogger.IPAnonymizationConfig{
@@ -112,7 +112,7 @@ func TestSubgraphAccessLogger(t *testing.T) {
 	t.Run("Should hash client IP and add it as a custom attribute", func(t *testing.T) {
 		var zCore zapcore.Core
 		zCore, logObserver := observer.New(zapcore.InfoLevel)
-		l := logging.NewZapLoggerWithCore(zCore, true)
+		l := logging.NewZapLoggerWithCore(zCore, true, true)
 
 		subgraphLogger := requestlogger.NewSubgraphAccessLogger(l, requestlogger.SubgraphOptions{
 			IPAnonymizationConfig: &requestlogger.IPAnonymizationConfig{
@@ -146,7 +146,7 @@ func TestSubgraphAccessLogger(t *testing.T) {
 	t.Run("calls fields handler and adds request/response headers", func(t *testing.T) {
 		var zCore zapcore.Core
 		zCore, logObserver := observer.New(zapcore.InfoLevel)
-		l := logging.NewZapLoggerWithCore(zCore, true)
+		l := logging.NewZapLoggerWithCore(zCore, true, true)
 
 		subgraphLogger := requestlogger.NewSubgraphAccessLogger(l, requestlogger.SubgraphOptions{
 			FieldsHandler: core.SubgraphAccessLogsFieldHandler,
@@ -196,7 +196,7 @@ func TestSubgraphAccessLogger(t *testing.T) {
 	t.Run("can handle a null request", func(t *testing.T) {
 		var zCore zapcore.Core
 		zCore, logObserver := observer.New(zapcore.InfoLevel)
-		l := logging.NewZapLoggerWithCore(zCore, true)
+		l := logging.NewZapLoggerWithCore(zCore, true, true)
 
 		subgraphLogger := requestlogger.NewSubgraphAccessLogger(l, requestlogger.SubgraphOptions{
 			FieldsHandler: core.SubgraphAccessLogsFieldHandler,

router/pkg/config/config.go

@@ -869,11 +869,13 @@ type AutomaticPersistedQueriesConfig struct {
 }
 
 type AccessLogsConfig struct {
-	Enabled   bool                      `yaml:"enabled" env:"ACCESS_LOGS_ENABLED" envDefault:"true"`
-	Buffer    AccessLogsBufferConfig    `yaml:"buffer,omitempty" env:"ACCESS_LOGS_BUFFER"`
-	Output    AccessLogsOutputConfig    `yaml:"output,omitempty" env:"ACCESS_LOGS_OUTPUT"`
-	Router    AccessLogsRouterConfig    `yaml:"router,omitempty" env:"ACCESS_LOGS_ROUTER"`
-	Subgraphs AccessLogsSubgraphsConfig `yaml:"subgraphs,omitempty" env:"ACCESS_LOGS_SUBGRAPH"`
+	Enabled       bool                      `yaml:"enabled" env:"ACCESS_LOGS_ENABLED" envDefault:"true"`
+	Level         string                    `yaml:"level" env:"ACCESS_LOGS_LEVEL" envDefault:"info"`
+	AddStacktrace bool                      `yaml:"add_stacktrace" env:"ACCESS_LOGS_ADD_STACKTRACE" envDefault:"false"`
+	Buffer        AccessLogsBufferConfig    `yaml:"buffer,omitempty" env:"ACCESS_LOGS_BUFFER"`
+	Output        AccessLogsOutputConfig    `yaml:"output,omitempty" env:"ACCESS_LOGS_OUTPUT"`
+	Router        AccessLogsRouterConfig    `yaml:"router,omitempty" env:"ACCESS_LOGS_ROUTER"`
+	Subgraphs     AccessLogsSubgraphsConfig `yaml:"subgraphs,omitempty" env:"ACCESS_LOGS_SUBGRAPH"`
 }
 
 type BatchingConfig struct {

router/pkg/config/config.schema.json

@@ -624,6 +624,17 @@
           "description": "Enable the access logs. The access logs are used to log the incoming requests. By default, the access logs are enabled and logged to the standard output.",
           "default": true
         },
+        "level": {
+          "type": "string",
+          "enum": ["debug", "info", "warn", "error", "panic", "fatal"],
+          "description": "The log level for access logs. The log level is used to control the verbosity of the access logs. The default value is 'info'.",
+          "default": "info"
+        },
+        "add_stacktrace": {
+          "type": "boolean",
+          "description": "Add stack traces to access logs when enabled for all error logs. When disabled, panic error logs will still contain stack traces. The default value is false.",
+          "default": true
+        },
         "buffer": {
           "type": "object",
           "additionalProperties": false,

router/pkg/config/testdata/config_defaults.json

@@ -188,6 +188,8 @@
   },
   "AccessLogs": {
     "Enabled": true,
+    "Level": "info",
+    "AddStacktrace": false,
     "Buffer": {
       "Enabled": false,
       "Size": 256000,

router/pkg/config/testdata/config_full.json

@@ -386,6 +386,8 @@
   },
   "AccessLogs": {
     "Enabled": true,
+    "Level": "info",
+    "AddStacktrace": false,
     "Buffer": {
       "Enabled": false,
       "Size": 256000,