feat: switch logging to slog (#328)

Signed-off-by: Ales Verbic <[email protected]>

Author: verbotenj

cmd/cardano-node-api/main.go

@@ -52,40 +52,29 @@ func main() {
 	}
 
 	// Configure logging
-	logging.Setup(&cfg.Logging)
+	logging.Configure()
 	logger := logging.GetLogger()
-	// Sync logger on exit
-	defer func() {
-		if err := logger.Sync(); err != nil {
-			// We don't actually care about the error here, but we have to do something
-			// to appease the linter
-			return
-		}
-	}()
 
 	// Test node connection
 	if cfg.Node.SkipCheck {
-		logger.Debugf("skipping node check")
+		logger.Debug("skipping node check")
 	} else {
 		if oConn, err := node.GetConnection(nil); err != nil {
-			logger.Fatalf("failed to connect to node: %s", err)
+			logger.Error("failed to connect to node:", "error", err)
 		} else {
 			oConn.Close()
 		}
 	}
 
-	logger.Infof(
-		"starting cardano-node-api version %s",
-		version.GetVersionString(),
-	)
+	logger.Info("starting cardano-node-api version", "version", version.GetVersionString())
 
 	// Start debug listener
 	if cfg.Debug.ListenPort > 0 {
-		logger.Infof(
+		logger.Info(fmt.Sprintf(
 			"starting debug listener on %s:%d",
 			cfg.Debug.ListenAddress,
 			cfg.Debug.ListenPort,
-		)
+		))
 		go func() {
 			err := http.ListenAndServe(
 				fmt.Sprintf(
@@ -96,21 +85,24 @@ func main() {
 				nil,
 			)
 			if err != nil {
-				logger.Fatalf("failed to start debug listener: %s", err)
+				logger.Error("failed to start debug listener:", "error", err)
+				os.Exit(1)
 			}
 		}()
 	}
 
 	// Start API listener
 	go func() {
 		if err := api.Start(cfg); err != nil {
-			logger.Fatalf("failed to start API: %s", err)
+			logger.Error("failed to start API:", "error", err)
+			os.Exit(1)
 		}
 	}()
 
 	// Start UTxO RPC gRPC listener
 	if err := utxorpc.Start(cfg); err != nil {
-		logger.Fatalf("failed to start gRPC: %s", err)
+		logger.Error("failed to start gRPC:", "error", err)
+		os.Exit(1)
 	}
 
 	// Wait forever

internal/api/api.go

@@ -16,12 +16,11 @@ package api
 
 import (
 	"fmt"
-	"time"
+	"os"
 
 	"github.com/blinklabs-io/cardano-node-api/internal/config"
 	"github.com/blinklabs-io/cardano-node-api/internal/logging"
 
-	ginzap "github.com/gin-contrib/zap"
 	"github.com/gin-gonic/gin"
 	"github.com/penglongli/gin-metrics/ginmetrics"
 
@@ -44,17 +43,17 @@ func Start(cfg *config.Config) error {
 	// Standard logging
 	logger := logging.GetLogger()
 	if cfg.Tls.CertFilePath != "" && cfg.Tls.KeyFilePath != "" {
-		logger.Infof(
+		logger.Info(fmt.Sprintf(
 			"starting API TLS listener on %s:%d",
 			cfg.Api.ListenAddress,
 			cfg.Api.ListenPort,
-		)
+		))
 	} else {
-		logger.Infof(
+		logger.Info(fmt.Sprintf(
 			"starting API listener on %s:%d",
 			cfg.Api.ListenAddress,
 			cfg.Api.ListenPort,
-		)
+		))
 	}
 	// Disable gin debug and color output
 	gin.SetMode(gin.ReleaseMode)
@@ -69,14 +68,15 @@ func Start(cfg *config.Config) error {
 	skipPaths := []string{}
 	if cfg.Logging.Healthchecks {
 		skipPaths = append(skipPaths, "/healthcheck")
-		logger.Infof("disabling access logs for /healthcheck")
+		logger.Info("disabling access logs for /healthcheck")
 	}
-	router.Use(ginzap.GinzapWithConfig(accessLogger, &ginzap.Config{
-		TimeFormat: time.RFC3339,
-		UTC:        true,
-		SkipPaths:  skipPaths,
-	}))
-	router.Use(ginzap.RecoveryWithZap(accessLogger, true))
+	accessMiddleware := func(c *gin.Context) {
+		accessLogger.Info("request received", "method", c.Request.Method, "path", c.Request.URL.Path, "remote_addr", c.ClientIP())
+		c.Next()
+		statusCode := c.Writer.Status()
+		accessLogger.Info("response sent", "status", statusCode, "method", c.Request.Method, "path", c.Request.URL.Path, "remote_addr", c.ClientIP())
+	}
+	router.Use(accessMiddleware)
 
 	// Create a healthcheck
 	router.GET("/healthcheck", handleHealthcheck)
@@ -104,14 +104,15 @@ func Start(cfg *config.Config) error {
 	// Start metrics listener
 	go func() {
 		// TODO: return error if we cannot initialize metrics
-		logger.Infof("starting metrics listener on %s:%d",
+		logger.Info(fmt.Sprintf("starting metrics listener on %s:%d",
 			cfg.Metrics.ListenAddress,
-			cfg.Metrics.ListenPort)
+			cfg.Metrics.ListenPort))
 		err := metricsRouter.Run(fmt.Sprintf("%s:%d",
 			cfg.Metrics.ListenAddress,
 			cfg.Metrics.ListenPort))
 		if err != nil {
-			logger.Fatalf("failed to start metrics listener: %s", err)
+			logger.Error("failed to start metrics listener:", "error", err)
+			os.Exit(1)
 		}
 	}()
 

internal/api/localtxsubmission.go

@@ -50,7 +50,7 @@ func handleLocalSubmitTx(c *gin.Context) {
 	// Check our headers for content-type
 	if c.ContentType() != "application/cbor" {
 		// Log the error, return an error to the user, and increment failed count
-		logger.Errorf("invalid request body, should be application/cbor")
+		logger.Error("invalid request body, should be application/cbor")
 		c.JSON(415, "invalid request body, should be application/cbor")
 		// _ = ginmetrics.GetMonitor().GetMetric("tx_submit_fail_count").Inc(nil)
 		return
@@ -59,15 +59,15 @@ func handleLocalSubmitTx(c *gin.Context) {
 	txRawBytes, err := io.ReadAll(c.Request.Body)
 	if err != nil {
 		// Log the error, return an error to the user, and increment failed count
-		logger.Errorf("failed to read request body: %s", err)
+		logger.Error("failed to read request body:", "error", err)
 		c.JSON(500, "failed to read request body")
 		// _ = ginmetrics.GetMonitor().GetMetric("tx_submit_fail_count").Inc(nil)
 		return
 	}
 	// Close request body after read
 	if c.Request.Body != nil {
 		if err = c.Request.Body.Close(); err != nil {
-			logger.Errorf("failed to close request body: %s", err)
+			logger.Error("failed to close request body:", "error", err)
 		}
 	}
 	// Send TX
@@ -99,7 +99,7 @@ func handleLocalSubmitTx(c *gin.Context) {
 	go func() {
 		err, ok := <-errorChan
 		if ok {
-			logger.Errorf("failure communicating with node: %s", err)
+			logger.Error("failure communicating with node:", "error", err)
 			c.JSON(500, "failure communicating with node")
 			// _ = ginmetrics.GetMonitor().GetMetric("tx_submit_fail_count").Inc(nil)
 		}

internal/logging/logging.go

@@ -1,4 +1,4 @@
-// Copyright 2023 Blink Labs Software
+// Copyright 2024 Blink Labs Software
 //
 // Licensed under the Apache License, Version 2.0 (the "License");
 // you may not use this file except in compliance with the License.
@@ -15,56 +15,75 @@
 package logging
 
 import (
-	"github.com/blinklabs-io/cardano-node-api/internal/config"
-	"go.uber.org/zap"
-	"go.uber.org/zap/zapcore"
-	"log"
+	"log/slog"
+	"os"
 	"time"
-)
-
-type Logger = zap.SugaredLogger
 
-var globalLogger *Logger
+	"github.com/blinklabs-io/cardano-node-api/internal/config"
+)
 
-func Setup(cfg *config.LoggingConfig) {
-	// Build our custom logging config
-	loggerConfig := zap.NewProductionConfig()
-	// Change timestamp key name
-	loggerConfig.EncoderConfig.TimeKey = "timestamp"
-	// Use a human readable time format
-	loggerConfig.EncoderConfig.EncodeTime = zapcore.TimeEncoderOfLayout(
-		time.RFC3339,
-	)
+var globalLogger *slog.Logger
+var accessLogger *slog.Logger
 
-	// Set level
-	if cfg.Level != "" {
-		level, err := zapcore.ParseLevel(cfg.Level)
-		if err != nil {
-			log.Fatalf("error configuring logger: %s", err)
-		}
-		loggerConfig.Level.SetLevel(level)
+// Configure initializes the global logger.
+func Configure() {
+	cfg := config.GetConfig()
+	var level slog.Level
+	switch cfg.Logging.Level {
+	case "debug":
+		level = slog.LevelDebug
+	case "info":
+		level = slog.LevelInfo
+	case "warn":
+		level = slog.LevelWarn
+	case "error":
+		level = slog.LevelError
+	default:
+		level = slog.LevelInfo
 	}
 
-	// Create the logger
-	l, err := loggerConfig.Build()
-	if err != nil {
-		log.Fatal(err)
-	}
+	handler := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
+		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
+			if a.Key == slog.TimeKey {
+				return slog.String(
+					"timestamp",
+					a.Value.Time().Format(time.RFC3339),
+				)
+			}
+			return a
+		},
+		Level: level,
+	})
+	globalLogger = slog.New(handler).With("component", "main")
 
-	// Store the "sugared" version of the logger
-	globalLogger = l.Sugar()
+	// Configure access logger
+	accessHandler := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
+		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
+			if a.Key == slog.TimeKey {
+				return slog.String(
+					"timestamp",
+					a.Value.Time().Format(time.RFC3339),
+				)
+			}
+			return a
+		},
+		Level: slog.LevelInfo,
+	})
+	accessLogger = slog.New(accessHandler).With("component", "access")
 }
 
-func GetLogger() *zap.SugaredLogger {
+// GetLogger returns the global application logger.
+func GetLogger() *slog.Logger {
+	if globalLogger == nil {
+		Configure()
+	}
 	return globalLogger
 }
 
-func GetDesugaredLogger() *zap.Logger {
-	return globalLogger.Desugar()
-}
-
-func GetAccessLogger() *zap.Logger {
-	return globalLogger.Desugar().
-		With(zap.String("type", "access")).
-		WithOptions(zap.WithCaller(false))
+// GetAccessLogger returns the access logger.
+func GetAccessLogger() *slog.Logger {
+	if accessLogger == nil {
+		Configure()
+	}
+	return accessLogger
 }

internal/utxorpc/api.go

@@ -36,17 +36,17 @@ func Start(cfg *config.Config) error {
 	// Standard logging
 	logger := logging.GetLogger()
 	if cfg.Tls.CertFilePath != "" && cfg.Tls.KeyFilePath != "" {
-		logger.Infof(
-			"starting gRPC TLS listener on %s:%d",
+		logger.Info(fmt.Sprintf(
+			"starting gRPC TLS listener on: %s:%d",
 			cfg.Utxorpc.ListenAddress,
 			cfg.Utxorpc.ListenPort,
-		)
+		))
 	} else {
-		logger.Infof(
+		logger.Info(fmt.Sprintf(
 			"starting gRPC listener on %s:%d",
 			cfg.Utxorpc.ListenAddress,
 			cfg.Utxorpc.ListenPort,
-		)
+		))
 	}
 	mux := http.NewServeMux()
 	compress1KB := connect.WithCompressMinBytes(1024)