avoid fmt.Sprintf logging

Author: serprex

canal/dump.go

@@ -186,8 +186,7 @@ func (c *Canal) dump() error {
 		c.master.UpdateGTIDSet(h.gset)
 		startPos = h.gset
 	}
-	c.cfg.Logger.Info(fmt.Sprintf("dump MySQL and parse OK, use %0.2f seconds, start binlog replication at %s",
-		time.Since(start).Seconds(), startPos))
+	c.cfg.Logger.Info("dump MySQL and parse OK", slog.Duration("use", time.Since(start)), slog.String("position", startPos.String()))
 	return nil
 }
 
@@ -197,7 +196,7 @@ func (c *Canal) tryDump() error {
 	if (len(pos.Name) > 0 && pos.Pos > 0) ||
 		(gset != nil && gset.String() != "") {
 		// we will sync with binlog name and position
-		c.cfg.Logger.Info(fmt.Sprintf("skip dump, use last binlog replication pos %s or GTID set %v", pos, gset))
+		c.cfg.Logger.Info("skip dump, use last binlog replication position or GTID set", slog.String("file", pos.Name), slog.Uint64("position", uint64(pos.Pos)), slog.Any("GTID set", gset))
 		return nil
 	}
 

canal/sync.go

@@ -1,7 +1,6 @@
 package canal
 
 import (
-	"fmt"
 	"log/slog"
 	"sync/atomic"
 	"time"
@@ -103,9 +102,8 @@ func (c *Canal) handleEvent(ev *replication.BinlogEvent) error {
 		}
 	case *replication.RowsEvent:
 		// we only focus row based event
-		err = c.handleRowsEvent(ev)
-		if err != nil {
-			c.cfg.Logger.Error(fmt.Sprintf("handle rows event at (%s, %d)", pos.Name, curPos), slog.Any("error", err))
+		if err := c.handleRowsEvent(ev); err != nil {
+			c.cfg.Logger.Error("handle rows event", slog.String("file", pos.Name), slog.Uint64("position", uint64(curPos)), slog.Any("error", err))
 			return errors.Trace(err)
 		}
 		return nil
@@ -115,7 +113,7 @@ func (c *Canal) handleEvent(ev *replication.BinlogEvent) error {
 		for _, subEvent := range ev.Events {
 			err = c.handleEvent(subEvent)
 			if err != nil {
-				c.cfg.Logger.Error(fmt.Sprintf("handle transaction payload subevent at (%s, %d)", pos.Name, curPos), slog.Any("error", err))
+				c.cfg.Logger.Error("handle transaction payload subevent", slog.String("file", pos.Name), slog.Uint64("position", uint64(curPos)), slog.Any("error", err))
 				return errors.Trace(err)
 			}
 		}
@@ -318,7 +316,8 @@ func (c *Canal) WaitUntilPos(pos mysql.Position, timeout time.Duration) error {
 			if curPos.Compare(pos) >= 0 {
 				return nil
 			} else {
-				c.cfg.Logger.Debug(fmt.Sprintf("master pos is %v, wait catching %v", curPos, pos))
+				c.cfg.Logger.Debug("master pos is behind, wait to catch up", slog.String("master file", curPos.Name), slog.Uint64("master position", uint64(curPos.Pos)),
+					slog.String("target file", pos.Name), slog.Uint64("target position", uint64(curPos.Pos)))
 				time.Sleep(100 * time.Millisecond)
 			}
 		}

replication/binlogsyncer.go

@@ -346,7 +346,7 @@ func (b *BinlogSyncer) registerSlave() error {
 		return errors.Trace(err)
 	}
 	if _, err = b.c.Execute(fmt.Sprintf("SET @slave_uuid = '%s', @replica_uuid = '%s'", serverUUID, serverUUID)); err != nil {
-		b.cfg.Logger.Error(fmt.Sprintf("failed to set @slave_uuid = '%s'", serverUUID), slog.Any("error", err))
+		b.cfg.Logger.Error(fmt.Sprintf("failed to set @slave_uuid = '%s', @replica_uuid = '%s'", serverUUID, serverUUID), slog.Any("error", err))
 		return errors.Trace(err)
 	}
 
@@ -653,17 +653,17 @@ func (b *BinlogSyncer) retrySync() error {
 	b.prevMySQLGTIDEvent = nil
 
 	if b.prevGset != nil {
-		msg := fmt.Sprintf("begin to re-sync from %s", b.prevGset.String())
+		extra := []interface{}{slog.String("GTID Set", b.prevGset.String())}
 		if b.currGset != nil {
-			msg = fmt.Sprintf("%s (last read GTID=%v)", msg, b.currGset)
+			extra = append(extra, slog.String("last read GTID", b.currGset.String()))
 		}
-		b.cfg.Logger.Info(msg)
+		b.cfg.Logger.Info("begin to re-sync", extra...)
 
 		if err := b.prepareSyncGTID(b.prevGset); err != nil {
 			return errors.Trace(err)
 		}
 	} else {
-		b.cfg.Logger.Info(fmt.Sprintf("begin to re-sync from %s", b.nextPos))
+		b.cfg.Logger.Info("begin to re-sync", slog.String("file", b.nextPos.Name), slog.Uint64("position", uint64(b.nextPos.Pos)))
 		if err := b.prepareSyncPos(b.nextPos); err != nil {
 			return errors.Trace(err)
 		}
@@ -856,7 +856,7 @@ func (b *BinlogSyncer) handleEventAndACK(s *BinlogStreamer, e *BinlogEvent, need
 	case *RotateEvent:
 		b.nextPos.Name = string(event.NextLogName)
 		b.nextPos.Pos = uint32(event.Position)
-		b.cfg.Logger.Info("rotate to next binlog", slog.String("file", b.nextPos.Name), slog.Int("position", b.nextPos))
+		b.cfg.Logger.Info("rotate to next binlog", slog.String("file", b.nextPos.Name), slog.Uint64("position", uint64(b.nextPos.Pos)))
 
 	case *GTIDEvent:
 		if b.prevGset == nil {