From 4604e48df53e267ad53d433f459d75b6211f66a0 Mon Sep 17 00:00:00 2001 From: Ales Verbic Date: Mon, 23 Sep 2024 21:48:18 -0400 Subject: [PATCH] chore: switch to slog for logging (#253) --- cmd/adder/main.go | 30 +++++++-------- fcm/message.go | 4 +- go.mod | 2 - go.sum | 4 -- input/chainsync/chainsync.go | 18 ++++----- internal/logging/logging.go | 72 ++++++++++++++++-------------------- output/log/log.go | 27 +++++++------- output/push/push.go | 44 +++++++++++----------- output/webhook/webhook.go | 12 +++--- plugin/log.go | 15 +++++--- 10 files changed, 107 insertions(+), 121 deletions(-) diff --git a/cmd/adder/main.go b/cmd/adder/main.go index ce26ecd..6c4de96 100644 --- a/cmd/adder/main.go +++ b/cmd/adder/main.go @@ -86,22 +86,14 @@ func main() { // Configure 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 - } - }() // 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( @@ -112,7 +104,8 @@ func main() { nil, ) if err != nil { - logger.Fatalf("failed to start debug listener: %s", err) + logger.Error(fmt.Sprintf("failed to start debug listener: %s", err)) + os.Exit(1) } }() } @@ -129,7 +122,8 @@ func main() { // Configure input input := plugin.GetPlugin(plugin.PluginTypeInput, cfg.Input) if input == nil { - logger.Fatalf("unknown input: %s", cfg.Input) + logger.Error(fmt.Sprintf("unknown input: %s", cfg.Input)) + os.Exit(1) } pipe.AddInput(input) @@ -142,7 +136,8 @@ func main() { // Configure output output := plugin.GetPlugin(plugin.PluginTypeOutput, cfg.Output) if output == nil { - logger.Fatalf("unknown output: %s", cfg.Output) + logger.Error(fmt.Sprintf("unknown output: %s", cfg.Output)) + os.Exit(1) } // Check if output plugin implements APIRouteRegistrar if registrar, ok := interface{}(output).(api.APIRouteRegistrar); ok { @@ -152,15 +147,18 @@ func main() { // Start API after plugins are configured if err := apiInstance.Start(); err != nil { - logger.Fatalf("failed to start API: %s", err) + logger.Error(fmt.Sprintf("failed to start API: %s", err)) + os.Exit(1) } // Start pipeline and wait for error if err := pipe.Start(); err != nil { - logger.Fatalf("failed to start pipeline: %s", err) + logger.Error(fmt.Sprintf("failed to start pipeline: %s", err)) + os.Exit(1) } err, ok := <-pipe.ErrorChan() if ok { - logger.Fatalf("pipeline failed: %s", err) + logger.Error(fmt.Sprintf("pipeline failed: %s", err)) + os.Exit(1) } } diff --git a/fcm/message.go b/fcm/message.go index 189fbaf..ef8b3e8 100644 --- a/fcm/message.go +++ b/fcm/message.go @@ -7,6 +7,7 @@ import ( "fmt" "io" "net/http" + "os" "github.com/blinklabs-io/adder/internal/logging" ) @@ -45,7 +46,8 @@ func WithNotification(title string, body string) MessageOption { func NewMessage(token string, opts ...MessageOption) *Message { if token == "" { - logging.GetLogger().Fatalf("Token is mandatory for FCM message") + logging.GetLogger().Error("Token is mandatory for FCM message") + os.Exit(1) } msg := &Message{ diff --git a/go.mod b/go.mod index ce5eba1..6a24190 100644 --- a/go.mod +++ b/go.mod @@ -14,7 +14,6 @@ require ( github.com/swaggo/gin-swagger v1.6.0 github.com/swaggo/swag v1.16.3 go.uber.org/automaxprocs v1.5.3 - go.uber.org/zap v1.27.0 golang.org/x/oauth2 v0.23.0 gopkg.in/yaml.v2 v2.4.0 ) @@ -62,7 +61,6 @@ require ( github.com/ugorji/go/codec v1.2.12 // indirect github.com/utxorpc/go-codegen v0.9.0 // indirect github.com/x448/float16 v0.8.4 // indirect - go.uber.org/multierr v1.10.0 // indirect golang.org/x/arch v0.8.0 // indirect golang.org/x/crypto v0.27.0 // indirect golang.org/x/net v0.25.0 // indirect diff --git a/go.sum b/go.sum index 39b6d2e..c8b50d2 100644 --- a/go.sum +++ b/go.sum @@ -145,10 +145,6 @@ go.uber.org/automaxprocs v1.5.3 h1:kWazyxZUrS3Gs4qUpbwo5kEIMGe/DAvi5Z4tl2NW4j8= go.uber.org/automaxprocs v1.5.3/go.mod h1:eRbA25aqJrxAbsLO0xy5jVwPt7FQnRgjW+efnwa1WM0= go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto= go.uber.org/goleak v1.3.0/go.mod h1:CoHD4mav9JJNrW/WLlf7HGZPjdw8EucARQHekz1X6bE= -go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ= -go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= -go.uber.org/zap v1.27.0 h1:aJMhYGrd5QSmlpLMr2MftRKl7t8J8PTZPA732ud/XR8= -go.uber.org/zap v1.27.0/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E= golang.org/x/arch v0.0.0-20210923205945-b76863e36670/go.mod h1:5om86z9Hs0C8fWVUuoMHwpExlXzs5Tkyp9hOrfG7pp8= golang.org/x/arch v0.8.0 h1:3wRIsP3pM4yUptoR96otTUOXI367OS0+c9eeRi9doIc= golang.org/x/arch v0.8.0/go.mod h1:FEVrYAQjsQXMVJ1nsMoVVXPZg6p2JE2mx8psSWTDQys= diff --git a/input/chainsync/chainsync.go b/input/chainsync/chainsync.go index cfc3f71..acf7a54 100644 --- a/input/chainsync/chainsync.go +++ b/input/chainsync/chainsync.go @@ -216,7 +216,7 @@ func (c *ChainSync) setupConnection() error { return err } if c.logger != nil { - c.logger.Infof("connected to node at %s", c.dialAddress) + c.logger.Info(fmt.Sprintf("connected to node at %s", c.dialAddress)) } // Start async error handler go func() { @@ -225,18 +225,18 @@ func (c *ChainSync) setupConnection() error { if c.autoReconnect { c.autoReconnectDelay = 0 if c.logger != nil { - c.logger.Infof( + c.logger.Info(fmt.Sprintf( "reconnecting to %s due to error: %s", c.dialAddress, err, - ) + )) } for { if c.autoReconnectDelay > 0 { - c.logger.Infof( + c.logger.Info(fmt.Sprintf( "waiting %s to reconnect", c.autoReconnectDelay, - ) + )) time.Sleep(c.autoReconnectDelay) // Double current reconnect delay up to maximum c.autoReconnectDelay = min( @@ -250,10 +250,10 @@ func (c *ChainSync) setupConnection() error { // Shutdown current connection if err := c.oConn.Close(); err != nil { if c.logger != nil { - c.logger.Warnf( + c.logger.Warn(fmt.Sprintf( "failed to properly close connection: %s", err, - ) + )) } } // Set the intersect points from the cursor cache @@ -263,11 +263,11 @@ func (c *ChainSync) setupConnection() error { // Restart the connection if err := c.Start(); err != nil { if c.logger != nil { - c.logger.Infof( + c.logger.Info(fmt.Sprintf( "reconnecting to %s due to error: %s", c.dialAddress, err, - ) + )) } continue } diff --git a/internal/logging/logging.go b/internal/logging/logging.go index f842437..e393ac5 100644 --- a/internal/logging/logging.go +++ b/internal/logging/logging.go @@ -15,59 +15,49 @@ package logging import ( - "log" + "log/slog" + "os" "time" "github.com/blinklabs-io/adder/internal/config" - - "go.uber.org/zap" - "go.uber.org/zap/zapcore" ) -type Logger = zap.SugaredLogger - -var globalLogger *Logger +var globalLogger *slog.Logger func Configure() { cfg := config.GetConfig() - // 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, - ) - - // Set level - if cfg.Logging.Level != "" { - level, err := zapcore.ParseLevel(cfg.Logging.Level) - if err != nil { - log.Fatalf("error configuring logger: %s", err) - } - loggerConfig.Level.SetLevel(level) + 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 { + // Format the time attribute to use RFC3339 or your custom format + // Rename the time key to timestamp + 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() } -func GetLogger() *zap.SugaredLogger { +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)) -} diff --git a/output/log/log.go b/output/log/log.go index a96948a..2c08ff1 100644 --- a/output/log/log.go +++ b/output/log/log.go @@ -15,6 +15,8 @@ package log import ( + "log/slog" + "github.com/blinklabs-io/adder/event" "github.com/blinklabs-io/adder/internal/logging" "github.com/blinklabs-io/adder/plugin" @@ -24,7 +26,7 @@ type LogOutput struct { errorChan chan error eventChan chan event.Event logger plugin.Logger - outputLogger *logging.Logger + outputLogger *slog.Logger level string } @@ -40,16 +42,13 @@ func New(options ...LogOptionFunc) *LogOutput { if l.logger == nil { l.logger = logging.GetLogger() } - // Determine if we can use the provided logger or need our own - // This is necessary because this plugin uses logger functions that aren't part - // of the plugin.Logger interface - switch v := l.logger.(type) { - case *logging.Logger: - l.outputLogger = v - default: - l.outputLogger = logging.GetLogger() + + // Use the provided *slog.Logger if available, otherwise fall back to global logger + if providedLogger, ok := l.logger.(*slog.Logger); ok { + l.outputLogger = providedLogger.With("type", "event") + } else { + l.outputLogger = logging.GetLogger().With("type", "event") } - l.outputLogger = l.outputLogger.With("type", "event") return l } @@ -64,14 +63,14 @@ func (l *LogOutput) Start() error { } switch l.level { case "info": - l.outputLogger.Infow("", "event", evt) + l.outputLogger.Info("", "event", evt) case "warn": - l.outputLogger.Warnw("", "event", evt) + l.outputLogger.Warn("", "event", evt) case "error": - l.outputLogger.Errorw("", "event", evt) + l.outputLogger.Error("", "event", evt) default: // Use INFO level if log level isn't recognized - l.outputLogger.Infow("", "event", evt) + l.outputLogger.Info("", "event", evt) } } }() diff --git a/output/push/push.go b/output/push/push.go index 535ce9a..a5dea10 100644 --- a/output/push/push.go +++ b/output/push/push.go @@ -60,14 +60,15 @@ func New(options ...PushOptionFunc) *PushOutput { } if err := p.GetProjectId(); err != nil { - logging.GetLogger().Fatalf("Failed to get project ID: %v", err) + logging.GetLogger().Error(fmt.Sprintf("Failed to get project ID: %v", err)) + os.Exit(1) } return p } func (p *PushOutput) Start() error { logger := logging.GetLogger() - logger.Infof("starting push notification server") + logger.Info("starting push notification server") go func() { for { evt, ok := <-p.eventChan @@ -93,13 +94,13 @@ func (p *PushOutput) Start() error { be := payload.(chainsync.BlockEvent) bc := context.(chainsync.BlockContext) - fmt.Println("Adder") - fmt.Printf( + logger.Debug("Adder") + logger.Debug(fmt.Sprintf( "New Block!\nBlockNumber: %d, SlotNumber: %d\nHash: %s", bc.BlockNumber, bc.SlotNumber, be.BlockHash, - ) + )) // Create notification message title := "Adder" @@ -120,11 +121,11 @@ func (p *PushOutput) Start() error { } re := payload.(chainsync.RollbackEvent) - fmt.Println("Adder") - fmt.Printf("Rollback!\nSlotNumber: %d\nBlockHash: %s", + logger.Debug("Adder") + logger.Debug(fmt.Sprintf("Rollback!\nSlotNumber: %d\nBlockHash: %s", re.SlotNumber, re.BlockHash, - ) + )) case "chainsync.transaction": payload := evt.Payload if payload == nil { @@ -204,8 +205,7 @@ func (p *PushOutput) processFcmNotifications(title, body string) { // If no FCM tokens exist, log and exit if len(p.fcmTokens) == 0 { - logging.GetLogger(). - Warnln("No FCM tokens found. Skipping notification.") + logging.GetLogger().Info("No FCM tokens found. Skipping notification.") return } @@ -217,33 +217,32 @@ func (p *PushOutput) processFcmNotifications(title, body string) { ) if err := fcm.Send(p.accessToken, p.projectID, msg); err != nil { - logging.GetLogger(). - Errorf("Failed to send message to token %s: %v", fcmToken, err) + logging.GetLogger().Error(fmt.Sprintf("Failed to send message to token %s: %v", fcmToken, err)) continue } - logging.GetLogger(). - Infof("Message sent successfully to token %s!", fcmToken) + logging.GetLogger().Info(fmt.Sprintf("Message sent successfully to token %s!", fcmToken)) } } func (p *PushOutput) GetAccessToken() error { data, err := os.ReadFile(p.serviceAccountFilePath) if err != nil { - logging.GetLogger(). - Fatalf("Failed to read the credential file: %v", err) + logging.GetLogger().Error(fmt.Sprintf("Failed to read the credential file: %v", err)) + os.Exit(1) return err } conf, err := google.JWTConfigFromJSON(data, p.accessTokenUrl) if err != nil { - logging.GetLogger(). - Fatalf("Failed to parse the credential file: %v", err) + logging.GetLogger().Error(fmt.Sprintf("Failed to parse the credential file: %v", err)) + os.Exit(1) return err } token, err := conf.TokenSource(context.Background()).Token() if err != nil { - logging.GetLogger().Fatalf("Failed to get token: %v", err) + logging.GetLogger().Error(fmt.Sprintf("Failed to get token: %v", err)) + os.Exit(1) return err } @@ -257,15 +256,16 @@ func (p *PushOutput) GetProjectId() error { data, err := os.ReadFile(p.serviceAccountFilePath) if err != nil { logging.GetLogger(). - Fatalf("Failed to read the credential file: %v", err) + Error(fmt.Sprintf("Failed to read the credential file: %v", err)) + os.Exit(1) return err } // Get project ID from file var v map[string]any if err := json.Unmarshal(data, &v); err != nil { - logging.GetLogger(). - Fatalf("Failed to parse the credential file: %v", err) + logging.GetLogger().Error(fmt.Sprintf("Failed to parse the credential file: %v", err)) + os.Exit(1) return err } p.projectID = v["project_id"].(string) diff --git a/output/webhook/webhook.go b/output/webhook/webhook.go index d259904..66f3542 100644 --- a/output/webhook/webhook.go +++ b/output/webhook/webhook.go @@ -68,7 +68,7 @@ func New(options ...WebhookOptionFunc) *WebhookOutput { // Start the webhook output func (w *WebhookOutput) Start() error { logger := logging.GetLogger() - logger.Infof("starting webhook server") + logger.Info("starting webhook server") go func() { for { evt, ok := <-w.eventChan @@ -97,13 +97,13 @@ func (w *WebhookOutput) Start() error { te := payload.(chainsync.TransactionEvent) evt.Payload = te default: - logger.Errorf("unknown event type: %s", evt.Type) + logger.Error(fmt.Sprintf("unknown event type: %s", evt.Type)) return } // TODO: error handle err := w.SendWebhook(&evt) if err != nil { - logger.Errorf("ERROR: %s", err) + logger.Error(fmt.Sprintf("ERROR: %s", err)) } } }() @@ -239,7 +239,7 @@ func getBaseURL(networkMagic uint32) string { func (w *WebhookOutput) SendWebhook(e *event.Event) error { logger := logging.GetLogger() - logger.Infof("sending event %s to %s", e.Type, w.url) + logger.Info(fmt.Sprintf("sending event %s to %s", e.Type, w.url)) data := formatWebhook(e, w.format) // Setup request ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) @@ -286,13 +286,13 @@ func (w *WebhookOutput) SendWebhook(e *event.Event) error { } defer resp.Body.Close() - logger.Infof("sent: %s, payload: %s, body: %s, response: %s, status: %d", + logger.Info(fmt.Sprintf("sent: %s, payload: %s, body: %s, response: %s, status: %d", w.url, string(data), string(respBody), resp.Status, resp.StatusCode, - ) + )) return nil } diff --git a/plugin/log.go b/plugin/log.go index a679573..01bbaf6 100644 --- a/plugin/log.go +++ b/plugin/log.go @@ -1,10 +1,13 @@ package plugin -// Logger provides a logging interface for plugins. This happens to match the interface of uber-go/zap +// Logger provides a logging interface for plugins. type Logger interface { - Infof(string, ...any) - Warnf(string, ...any) - Debugf(string, ...any) - Errorf(string, ...any) - Fatalf(string, ...any) + Info(string, ...any) + Warn(string, ...any) + Debug(string, ...any) + Error(string, ...any) + + // Deprecated + // Fatal(string, ...any) in favor of Error + // With slog Fatal is replaced with Error and os.Exit(1) }