Add logger (ibc-go v7)

cmd/config.go

@@ -156,6 +156,9 @@ func initConfig(ctx *config.Context, cmd *cobra.Command) error {
 				os.Exit(1)
 			}
 		}
+	} else {
+		defConfig := config.DefaultConfig()
+		ctx.Config = &defConfig
 	}
 	return nil
 }

cmd/root.go

@@ -9,6 +9,7 @@ import (
 
 	"github.com/hyperledger-labs/yui-relayer/config"
 	"github.com/hyperledger-labs/yui-relayer/core"
+	"github.com/hyperledger-labs/yui-relayer/log"
 	"github.com/hyperledger-labs/yui-relayer/metrics"
 
 	"github.com/cosmos/cosmos-sdk/client/flags"
@@ -80,6 +81,9 @@ func Execute(modules ...config.ModuleI) error {
 		if err := initConfig(ctx, rootCmd); err != nil {
 			return fmt.Errorf("failed to initialize the configuration: %v", err)
 		}
+		if err := initLogger(ctx); err != nil {
+			return err
+		}
 		if err := metrics.InitializeMetrics(metrics.ExporterNull{}); err != nil {
 			return fmt.Errorf("failed to initialize the metrics: %v", err)
 		}
@@ -101,6 +105,11 @@ func readStdin() (string, error) {
 	return strings.TrimSpace(str), err
 }
 
+func initLogger(ctx *config.Context) error {
+	c := ctx.Config.Global.LoggerConfig
+	return log.InitLogger(c.Level, c.Format, c.Output)
+}
+
 func noCommand(cmd *cobra.Command, args []string) error {
 	cmd.Help()
 	return errors.New("specified command does not exist")

config/config.go

@@ -27,15 +27,27 @@ func DefaultConfig() Config {
 
 // GlobalConfig describes any global relayer settings
 type GlobalConfig struct {
-	Timeout        string `yaml:"timeout" json:"timeout"`
-	LightCacheSize int    `yaml:"light-cache-size" json:"light-cache-size"`
+	Timeout        string       `yaml:"timeout" json:"timeout"`
+	LightCacheSize int          `yaml:"light-cache-size" json:"light-cache-size"`
+	LoggerConfig   LoggerConfig `yaml:"logger" json:"logger"`
+}
+
+type LoggerConfig struct {
+	Level  string `yaml:"level" json:"level"`
+	Format string `yaml:"format" json:"format"`
+	Output string `yaml:"output" json:"output"`
 }
 
 // newDefaultGlobalConfig returns a global config with defaults set
 func newDefaultGlobalConfig() GlobalConfig {
 	return GlobalConfig{
 		Timeout:        "10s",
 		LightCacheSize: 20,
+		LoggerConfig: LoggerConfig{
+			Level:  "DEBUG",
+			Format: "json",
+			Output: "stderr",
+		},
 	}
 }
 

core/chain.go

@@ -11,6 +11,7 @@ import (
 	conntypes "github.com/cosmos/ibc-go/v7/modules/core/03-connection/types"
 	chantypes "github.com/cosmos/ibc-go/v7/modules/core/04-channel/types"
 	ibcexported "github.com/cosmos/ibc-go/v7/modules/core/exported"
+	"github.com/hyperledger-labs/yui-relayer/log"
 )
 
 // ProvableChain represents a chain that is supported by the relayer
@@ -195,3 +196,12 @@ func (qc queryContext) Context() context.Context {
 func (qc queryContext) Height() ibcexported.Height {
 	return qc.height
 }
+
+func GetChainPairLogger(src, dst ChainInfo) *log.RelayLogger {
+	return log.GetLogger().
+		WithChainPair(
+			src.ChainID(),
+			dst.ChainID(),
+		).
+		WithModule("core.chain")
+}

core/channel.go

@@ -3,16 +3,18 @@ package core
 import (
 	"context"
 	"fmt"
-	"log"
 	"time"
 
 	retry "github.com/avast/retry-go"
 	chantypes "github.com/cosmos/ibc-go/v7/modules/core/04-channel/types"
+	"github.com/hyperledger-labs/yui-relayer/log"
+	"golang.org/x/exp/slog"
 )
 
 // CreateChannel runs the channel creation messages on timeout until they pass
 // TODO: add max retries or something to this function
 func CreateChannel(src, dst *ProvableChain, ordered bool, to time.Duration) error {
+	logger := GetChannelPairLogger(src, dst)
 	var order chantypes.Order
 	if ordered {
 		order = chantypes.ORDERED
@@ -25,11 +27,15 @@ func CreateChannel(src, dst *ProvableChain, ordered bool, to time.Duration) erro
 	for ; true; <-ticker.C {
 		chanSteps, err := createChannelStep(src, dst, order)
 		if err != nil {
+			logger.Error(
+				"failed to create channel step",
+				err,
+			)
 			return err
 		}
 
 		if !chanSteps.Ready() {
-			log.Println("Waiting for next channel step ...")
+			logger.Debug("Waiting for next channel step ...")
 			continue
 		}
 
@@ -39,9 +45,9 @@ func CreateChannel(src, dst *ProvableChain, ordered bool, to time.Duration) erro
 		// In the case of success and this being the last transaction
 		// debug logging, log created connection and break
 		case chanSteps.Success() && chanSteps.Last:
-			log.Printf("★ Channel created: [%s]chan{%s}port{%s} -> [%s]chan{%s}port{%s}",
-				src.ChainID(), src.Path().ChannelID, src.Path().PortID,
-				dst.ChainID(), dst.Path().ChannelID, dst.Path().PortID)
+			logger.Info(
+				"★ Channel created",
+			)
 			return nil
 		// In the case of success, reset the failures counter
 		case chanSteps.Success():
@@ -50,12 +56,17 @@ func CreateChannel(src, dst *ProvableChain, ordered bool, to time.Duration) erro
 		// In the case of failure, increment the failures counter and exit if this is the 3rd failure
 		case !chanSteps.Success():
 			failures++
-			log.Printf("retrying transaction...")
+			logger.Info("retrying transaction...")
 			time.Sleep(5 * time.Second)
 			if failures > 2 {
+				logger.Error(
+					"! Channel failed",
+					err,
+				)
 				return fmt.Errorf("! Channel failed: [%s]chan{%s}port{%s} -> [%s]chan{%s}port{%s}",
-					src.ChainID(), src.Path().ClientID, src.Path().ChannelID,
-					dst.ChainID(), dst.Path().ClientID, dst.Path().ChannelID)
+					src.ChainID(), src.Path().ChannelID, src.Path().PortID,
+					dst.ChainID(), dst.Path().ChannelID, dst.Path().PortID,
+				)
 			}
 		}
 	}
@@ -171,20 +182,22 @@ func createChannelStep(src, dst *ProvableChain, ordering chantypes.Order) (*Rela
 	return out, nil
 }
 
-func logChannelStates(src, dst Chain, srcChan, dstChan *chantypes.QueryChannelResponse) {
-	log.Printf("- [%s]@{%d}chan(%s)-{%s} : [%s]@{%d}chan(%s)-{%s}",
-		src.ChainID(),
-		mustGetHeight(srcChan.ProofHeight),
-		src.Path().ChannelID,
-		srcChan.Channel.State,
-		dst.ChainID(),
-		mustGetHeight(dstChan.ProofHeight),
-		dst.Path().ChannelID,
-		dstChan.Channel.State,
-	)
+func logChannelStates(src, dst *ProvableChain, srcChan, dstChan *chantypes.QueryChannelResponse) {
+	logger := GetChannelPairLogger(src, dst)
+	logger.Info(
+		"channel states",
+		slog.Group("src",
+			slog.Uint64("proof_height", mustGetHeight(srcChan.ProofHeight)),
+			slog.String("state", srcChan.Channel.State.String()),
+		),
+		slog.Group("dst",
+			slog.Uint64("proof_height", mustGetHeight(dstChan.ProofHeight)),
+			slog.String("state", dstChan.Channel.State.String()),
+		))
 }
 
 func checkChannelFinality(src, dst *ProvableChain, srcChannel, dstChannel *chantypes.Channel) (bool, error) {
+	logger := GetChannelPairLogger(src, dst)
 	sh, err := src.LatestHeight()
 	if err != nil {
 		return false, err
@@ -198,12 +211,29 @@ func checkChannelFinality(src, dst *ProvableChain, srcChannel, dstChannel *chant
 		return false, err
 	}
 	if srcChannel.State != srcChanLatest.Channel.State {
-		log.Printf("Source Channel: Finalized state [%s] <> Latest state [%s]", srcChannel.State, srcChanLatest.Channel.State)
+		logger.Debug("src channel state in transition", "from_state", srcChannel.State, "to_state", srcChanLatest.Channel.State)
 		return false, nil
 	}
 	if dstChannel.State != dstChanLatest.Channel.State {
-		log.Printf("Destination Channel: Finalized state [%s] <> Latest state [%s]", dstChannel.State, dstChanLatest.Channel.State)
+		logger.Debug("dst channel state in transition", "from_state", dstChannel.State, "to_state", dstChanLatest.Channel.State)
 		return false, nil
 	}
 	return true, nil
 }
+
+func GetChannelLogger(c Chain) *log.RelayLogger {
+	return log.GetLogger().
+		WithChannel(
+			c.ChainID(), c.Path().PortID, c.Path().ChannelID,
+		).
+		WithModule("core.channel")
+}
+
+func GetChannelPairLogger(src, dst Chain) *log.RelayLogger {
+	return log.GetLogger().
+		WithChannelPair(
+			src.ChainID(), src.Path().PortID, src.Path().ChannelID,
+			dst.ChainID(), dst.Path().PortID, dst.Path().ChannelID,
+		).
+		WithModule("core.channel")
+}

core/client.go

@@ -1,34 +1,50 @@
 package core
 
 import (
-	"log"
-
 	sdk "github.com/cosmos/cosmos-sdk/types"
+	"github.com/hyperledger-labs/yui-relayer/log"
 	"golang.org/x/sync/errgroup"
 )
 
 func CreateClients(src, dst *ProvableChain) error {
+	logger := GetChainPairLogger(src, dst)
 	var (
 		clients = &RelayMsgs{Src: []sdk.Msg{}, Dst: []sdk.Msg{}}
 	)
 
 	srcH, dstH, err := getHeadersForCreateClient(src, dst)
 	if err != nil {
+		logger.Error(
+			"failed to get headers for create client",
+			err,
+		)
 		return err
 	}
 
 	srcAddr, err := src.GetAddress()
 	if err != nil {
+		logger.Error(
+			"failed to get address for create client",
+			err,
+		)
 		return err
 	}
 	dstAddr, err := dst.GetAddress()
 	if err != nil {
+		logger.Error(
+			"failed to get address for create client",
+			err,
+		)
 		return err
 	}
 
 	{
 		msg, err := dst.CreateMsgCreateClient(src.Path().ClientID, dstH, srcAddr)
 		if err != nil {
+			logger.Error(
+				"failed to create client",
+				err,
+			)
 			return err
 		}
 		clients.Src = append(clients.Src, msg)
@@ -37,6 +53,10 @@ func CreateClients(src, dst *ProvableChain) error {
 	{
 		msg, err := src.CreateMsgCreateClient(dst.Path().ClientID, srcH, dstAddr)
 		if err != nil {
+			logger.Error(
+				"failed to create client",
+				err,
+			)
 			return err
 		}
 		clients.Dst = append(clients.Dst, msg)
@@ -46,24 +66,34 @@ func CreateClients(src, dst *ProvableChain) error {
 	if clients.Ready() {
 		// TODO: Add retry here for out of gas or other errors
 		if clients.Send(src, dst); clients.Success() {
-			log.Printf("★ Clients created: [%s]client(%s) and [%s]client(%s)",
-				src.ChainID(), src.Path().ClientID, dst.ChainID(), dst.Path().ClientID)
+			logger.Info(
+				"★ Clients created",
+			)
 		}
 	}
 	return nil
 }
 
 func UpdateClients(src, dst *ProvableChain) error {
+	logger := GetClientPairLogger(src, dst)
 	var (
 		clients = &RelayMsgs{Src: []sdk.Msg{}, Dst: []sdk.Msg{}}
 	)
 	// First, update the light clients to the latest header and return the header
 	sh, err := NewSyncHeaders(src, dst)
 	if err != nil {
+		logger.Error(
+			"failed to create sync headers for update client",
+			err,
+		)
 		return err
 	}
 	srcUpdateHeaders, dstUpdateHeaders, err := sh.SetupBothHeadersForUpdate(src, dst)
 	if err != nil {
+		logger.Error(
+			"failed to setup both headers for update client",
+			err,
+		)
 		return err
 	}
 	if len(dstUpdateHeaders) > 0 {
@@ -75,8 +105,9 @@ func UpdateClients(src, dst *ProvableChain) error {
 	// Send msgs to both chains
 	if clients.Ready() {
 		if clients.Send(src, dst); clients.Success() {
-			log.Printf("★ Clients updated: [%s]client(%s) and [%s]client(%s)",
-				src.ChainID(), src.Path().ClientID, dst.ChainID(), dst.Path().ClientID)
+			logger.Info(
+				"★ Clients updated",
+			)
 		}
 	}
 	return nil
@@ -98,3 +129,12 @@ func getHeadersForCreateClient(src, dst LightClient) (srch, dsth Header, err err
 	}
 	return srch, dsth, nil
 }
+
+func GetClientPairLogger(src, dst Chain) *log.RelayLogger {
+	return log.GetLogger().
+		WithClientPair(
+			src.ChainID(), src.Path().ClientID,
+			dst.ChainID(), dst.Path().ClientID,
+		).
+		WithModule("core.client")
+}

core/config.go

@@ -6,6 +6,7 @@ import (
 
 	"github.com/cosmos/cosmos-sdk/codec"
 	"github.com/cosmos/gogoproto/proto"
+	"github.com/hyperledger-labs/yui-relayer/log"
 	"github.com/hyperledger-labs/yui-relayer/utils"
 )
 
@@ -33,12 +34,15 @@ type ProverConfig interface {
 
 // NewChainProverConfig returns a new config instance
 func NewChainProverConfig(m codec.JSONCodec, chain ChainConfig, client ProverConfig) (*ChainProverConfig, error) {
+	logger := log.GetLogger().WithModule("core.config")
 	cbz, err := utils.MarshalJSONAny(m, chain)
 	if err != nil {
+		logger.Error("error marshalling chain config", err)
 		return nil, err
 	}
 	clbz, err := utils.MarshalJSONAny(m, client)
 	if err != nil {
+		logger.Error("error marshalling client config", err)
 		return nil, err
 	}
 	return &ChainProverConfig{