feat: improve logger

cosmos · Feb 27, 2023 · a018f11 · a018f11
1 parent 747c29e
commit a018f11
Show file tree

Hide file tree

Showing 97 changed files with 463 additions and 408 deletions.
diff --git a/baseapp/grpcrouter_test.go b/baseapp/grpcrouter_test.go
@@ -2,11 +2,10 @@ package baseapp_test
 
 import (
 	"context"
-	"os"
 	"sync"
 	"testing"
 
-	"github.com/cometbft/cometbft/libs/log"
+	"cosmossdk.io/log"
 	dbm "github.com/cosmos/cosmos-db"
 	"github.com/stretchr/testify/require"
 
@@ -59,7 +58,7 @@ func TestRegisterQueryServiceTwice(t *testing.T) {
 	err := depinject.Inject(makeMinimalConfig(), &appBuilder)
 	require.NoError(t, err)
 	db := dbm.NewMemDB()
-	app := appBuilder.Build(log.NewTMLogger(log.NewSyncWriter(os.Stdout)), db, nil)
+	app := appBuilder.Build(log.NewLogger(), db, nil)
 
 	// First time registering service shouldn't panic.
 	require.NotPanics(t, func() {

diff --git a/baseapp/msg_service_router_test.go b/baseapp/msg_service_router_test.go
@@ -1,16 +1,15 @@
 package baseapp_test
 
 import (
-	"os"
 	"testing"
 
 	abci "github.com/cometbft/cometbft/abci/types"
-	"github.com/cometbft/cometbft/libs/log"
 	cmtproto "github.com/cometbft/cometbft/proto/tendermint/types"
 	dbm "github.com/cosmos/cosmos-db"
 	"github.com/stretchr/testify/require"
 
 	"cosmossdk.io/depinject"
+	"cosmossdk.io/log"
 	"github.com/cosmos/cosmos-sdk/client/tx"
 	"github.com/cosmos/cosmos-sdk/codec"
 	codectypes "github.com/cosmos/cosmos-sdk/codec/types"
@@ -29,7 +28,7 @@ func TestRegisterMsgService(t *testing.T) {
 	)
 	err := depinject.Inject(makeMinimalConfig(), &appBuilder, &registry)
 	require.NoError(t, err)
-	app := appBuilder.Build(log.NewTMLogger(log.NewSyncWriter(os.Stdout)), dbm.NewMemDB(), nil)
+	app := appBuilder.Build(log.NewLogger(), dbm.NewMemDB(), nil)
 
 	require.Panics(t, func() {
 		testdata.RegisterMsgServer(
@@ -58,7 +57,7 @@ func TestRegisterMsgServiceTwice(t *testing.T) {
 	err := depinject.Inject(makeMinimalConfig(), &appBuilder, &registry)
 	require.NoError(t, err)
 	db := dbm.NewMemDB()
-	app := appBuilder.Build(log.NewTMLogger(log.NewSyncWriter(os.Stdout)), db, nil)
+	app := appBuilder.Build(log.NewLogger(), db, nil)
 	testdata.RegisterInterfaces(registry)
 
 	// First time registering service shouldn't panic.

diff --git a/baseapp/utils_test.go b/baseapp/utils_test.go
@@ -8,7 +8,6 @@ import (
 	"errors"
 	"fmt"
 	"net/url"
-	"os"
 	"reflect"
 	"strconv"
 	"testing"
@@ -21,12 +20,12 @@ import (
 	errorsmod "cosmossdk.io/errors"
 	sdkmath "cosmossdk.io/math"
 	storetypes "cosmossdk.io/store/types"
-	"github.com/cometbft/cometbft/libs/log"
 	cmtproto "github.com/cometbft/cometbft/proto/tendermint/types"
 	cmttypes "github.com/cometbft/cometbft/types"
 	dbm "github.com/cosmos/cosmos-db"
 	"github.com/stretchr/testify/require"
 
+	"cosmossdk.io/log"
 	"github.com/cosmos/cosmos-sdk/baseapp"
 	baseapptestutil "github.com/cosmos/cosmos-sdk/baseapp/testutil"
 	"github.com/cosmos/cosmos-sdk/client"
@@ -55,7 +54,7 @@ var ParamStoreKey = []byte("paramstore")
 
 func defaultLogger() log.Logger {
 	if testing.Verbose() {
-		return log.NewTMLogger(log.NewSyncWriter(os.Stdout)).With("module", "baseapp/test")
+		return log.NewLoggerWithKV("module", "baseapp/test")
 	}
 
 	return log.NewNopLogger()

diff --git a/client/pruning/main.go b/client/pruning/main.go
@@ -2,15 +2,14 @@ package pruning
 
 import (
 	"fmt"
-	"os"
 	"path/filepath"
 
 	"github.com/spf13/cobra"
 	"github.com/spf13/viper"
 
+	"cosmossdk.io/log"
 	pruningtypes "cosmossdk.io/store/pruning/types"
 	"cosmossdk.io/store/rootmulti"
-	"github.com/cometbft/cometbft/libs/log"
 	dbm "github.com/cosmos/cosmos-db"
 
 	"github.com/cosmos/cosmos-sdk/client/flags"
@@ -62,7 +61,7 @@ func Cmd(appCreator servertypes.AppCreator) *cobra.Command {
 				return err
 			}
 
-			logger := log.NewTMLogger(log.NewSyncWriter(os.Stdout))
+			logger := log.NewLogger()
 			app := appCreator(logger, db, nil, vp)
 			cms := app.CommitMultiStore()
 

diff --git a/client/v2/go.mod b/client/v2/go.mod
@@ -19,7 +19,7 @@ require (
 require (
 	cosmossdk.io/collections v0.0.0-20230214153846-b6c6e4e99177 // indirect
 	cosmossdk.io/errors v1.0.0-beta.7 // indirect
-	cosmossdk.io/log v0.0.0-20230219145338-9553bf1eec78 // indirect
+	cosmossdk.io/log v0.0.0-20230227110325-294ef34f396f // indirect
 	cosmossdk.io/math v1.0.0-beta.6.0.20230216172121-959ce49135e4 // indirect
 	cosmossdk.io/store v0.0.0-20230206092147-e03195e4b8a7 // indirect
 	filippo.io/edwards25519 v1.0.0 // indirect

diff --git a/client/v2/go.sum b/client/v2/go.sum
@@ -45,8 +45,8 @@ cosmossdk.io/depinject v1.0.0-alpha.3 h1:6evFIgj//Y3w09bqOUOzEpFj5tsxBqdc5CfkO7z
 cosmossdk.io/depinject v1.0.0-alpha.3/go.mod h1:eRbcdQ7MRpIPEM5YUJh8k97nxHpYbc3sMUnEtt8HPWU=
 cosmossdk.io/errors v1.0.0-beta.7 h1:gypHW76pTQGVnHKo6QBkb4yFOJjC+sUGRc5Al3Odj1w=
 cosmossdk.io/errors v1.0.0-beta.7/go.mod h1:mz6FQMJRku4bY7aqS/Gwfcmr/ue91roMEKAmDUDpBfE=
-cosmossdk.io/log v0.0.0-20230219145338-9553bf1eec78 h1:Scox9JfANgkuAO0F9LMH0e0W5ijmp2BQbsok/U+jDUo=
-cosmossdk.io/log v0.0.0-20230219145338-9553bf1eec78/go.mod h1:MyvZ6k9eL0azI/yf8m5gqsM8PgbtFmqjire1OxUMkmc=
+cosmossdk.io/log v0.0.0-20230227110325-294ef34f396f h1:8qg6pvpG4+K2woMBGIPvMDKJ4tlKZjYU+eX9ITY5iuA=
+cosmossdk.io/log v0.0.0-20230227110325-294ef34f396f/go.mod h1:FZRNfYm6Jgp+toyDR8Ek1qrmNjdsDddEQnfATMbpGYg=
 cosmossdk.io/math v1.0.0-beta.6.0.20230216172121-959ce49135e4 h1:/jnzJ9zFsL7qkV8LCQ1JH3dYHh2EsKZ3k8Mr6AqqiOA=
 cosmossdk.io/math v1.0.0-beta.6.0.20230216172121-959ce49135e4/go.mod h1:gUVtWwIzfSXqcOT+lBVz2jyjfua8DoBdzRsIyaUAT/8=
 cosmossdk.io/store v0.0.0-20230206092147-e03195e4b8a7 h1:IwyDN/YaQmF+Pmuv8d7vRWMM/k2RjSmPBycMcmd3ICE=

diff --git a/go.mod b/go.mod
@@ -8,9 +8,9 @@ require (
 	cosmossdk.io/core v0.5.1
 	cosmossdk.io/depinject v1.0.0-alpha.3
 	cosmossdk.io/errors v1.0.0-beta.7
-	cosmossdk.io/log v0.0.0-20230219145338-9553bf1eec78
+	cosmossdk.io/log v0.0.0-20230227110325-294ef34f396f
 	cosmossdk.io/math v1.0.0-beta.6.0.20230216172121-959ce49135e4
-	cosmossdk.io/store v0.0.0-20230206092147-e03195e4b8a7
+	cosmossdk.io/store v0.0.0-20230227103508-bbe7f8a11b44
 	cosmossdk.io/x/tx v0.2.0
 	github.com/99designs/keyring v1.2.1
 	github.com/armon/go-metrics v0.4.1

diff --git a/go.sum b/go.sum
@@ -45,12 +45,12 @@ cosmossdk.io/depinject v1.0.0-alpha.3 h1:6evFIgj//Y3w09bqOUOzEpFj5tsxBqdc5CfkO7z
 cosmossdk.io/depinject v1.0.0-alpha.3/go.mod h1:eRbcdQ7MRpIPEM5YUJh8k97nxHpYbc3sMUnEtt8HPWU=
 cosmossdk.io/errors v1.0.0-beta.7 h1:gypHW76pTQGVnHKo6QBkb4yFOJjC+sUGRc5Al3Odj1w=
 cosmossdk.io/errors v1.0.0-beta.7/go.mod h1:mz6FQMJRku4bY7aqS/Gwfcmr/ue91roMEKAmDUDpBfE=
-cosmossdk.io/log v0.0.0-20230219145338-9553bf1eec78 h1:Scox9JfANgkuAO0F9LMH0e0W5ijmp2BQbsok/U+jDUo=
-cosmossdk.io/log v0.0.0-20230219145338-9553bf1eec78/go.mod h1:MyvZ6k9eL0azI/yf8m5gqsM8PgbtFmqjire1OxUMkmc=
+cosmossdk.io/log v0.0.0-20230227110325-294ef34f396f h1:8qg6pvpG4+K2woMBGIPvMDKJ4tlKZjYU+eX9ITY5iuA=
+cosmossdk.io/log v0.0.0-20230227110325-294ef34f396f/go.mod h1:FZRNfYm6Jgp+toyDR8Ek1qrmNjdsDddEQnfATMbpGYg=
 cosmossdk.io/math v1.0.0-beta.6.0.20230216172121-959ce49135e4 h1:/jnzJ9zFsL7qkV8LCQ1JH3dYHh2EsKZ3k8Mr6AqqiOA=
 cosmossdk.io/math v1.0.0-beta.6.0.20230216172121-959ce49135e4/go.mod h1:gUVtWwIzfSXqcOT+lBVz2jyjfua8DoBdzRsIyaUAT/8=
-cosmossdk.io/store v0.0.0-20230206092147-e03195e4b8a7 h1:IwyDN/YaQmF+Pmuv8d7vRWMM/k2RjSmPBycMcmd3ICE=
-cosmossdk.io/store v0.0.0-20230206092147-e03195e4b8a7/go.mod h1:1XOtuYs7jsfQkn7G3VQXB6I+2tHXKHZw2U/AafNbnlk=
+cosmossdk.io/store v0.0.0-20230227103508-bbe7f8a11b44 h1:/pKsj/ApzO4+zMwpgLiPG5iakoHxziGpMiJcz4S+r4w=
+cosmossdk.io/store v0.0.0-20230227103508-bbe7f8a11b44/go.mod h1:flrxUykloEW1asE9p+Q+d8LSuNI3fBRdzISg9HTpYlQ=
 cosmossdk.io/x/tx v0.2.0 h1:53f5TIXhpPYJGMm47SUslcV2i8JNBEN3eE08BmxE/Zg=
 cosmossdk.io/x/tx v0.2.0/go.mod h1:CTko7wgt7aBdbxOesZ+Wo1uO/03ueKzIQ0iI323Rqgk=
 dmitri.shuralyov.com/gpu/mtl v0.0.0-20190408044501-666a987793e9/go.mod h1:H6x//7gZCb22OMCxBHrMx7a5I7Hp++hsVxbQ4BYO7hU=
@@ -630,8 +630,8 @@ github.com/nats-io/nkeys v0.1.0/go.mod h1:xpnFELMwJABBLVhffcfd1MZx6VsNRFpEugbxzi
 github.com/nats-io/nkeys v0.1.3/go.mod h1:xpnFELMwJABBLVhffcfd1MZx6VsNRFpEugbxziKVo7w=
 github.com/nats-io/nuid v1.0.1/go.mod h1:19wcPz3Ph3q0Jbyiqsd0kePYG7A95tJPxeL+1OSON2c=
 github.com/niemeyer/pretty v0.0.0-20200227124842-a10e7caefd8e/go.mod h1:zD1mROLANZcx1PVRCS0qkT7pwLkGfwJo4zjcN/Tysno=
+github.com/nxadm/tail v1.4.4 h1:DQuhQpB1tVlglWS2hLQ5OV6B5r8aGxSrPc5Qo6uTN78=
 github.com/nxadm/tail v1.4.4/go.mod h1:kenIhsEOeOJmVchQTgglprH7qJGnHDVpk1VPCcaMI8A=
-github.com/nxadm/tail v1.4.8 h1:nPr65rt6Y5JFSKQO7qToXr7pePgD6Gwiw05lkbyAQTE=
 github.com/oklog/oklog v0.3.2/go.mod h1:FCV+B7mhrz4o+ueLpx+KqkyXRGMWOYEvfiXtdGtbWGs=
 github.com/oklog/run v1.0.0/go.mod h1:dlhp/R75TPv97u0XWUtDeV/lRKWPKSdTuV0TZvrmrQA=
 github.com/olekukonko/tablewriter v0.0.0-20170122224234-a0225b3f23b5/go.mod h1:vsDQFd/mU46D+Z4whnwzcISnGGzXWMclvtLoiIKAKIo=

diff --git a/log/README.md b/log/README.md
@@ -1,3 +1,3 @@
 # Log
 
-The `cosmossdk.io/log` provides simple logging implementations for the Cosmos SDK and Cosmos SDK modules.
+The `cosmossdk.io/log` provides a zerolog logging implementation for the Cosmos SDK and Cosmos SDK modules.
diff --git a/log/bench_test.go b/log/bench_test.go
@@ -2,6 +2,7 @@ package log_test
 
 import (
 	"bytes"
+	"errors"
 	"io"
 	"testing"
 	"time"
@@ -10,6 +11,8 @@ import (
 	"github.com/rs/zerolog"
 )
 
+const message = "test message"
+
 func BenchmarkLoggers(b *testing.B) {
 	b.ReportAllocs()
 
@@ -61,14 +64,13 @@ func BenchmarkLoggers(b *testing.B) {
 		},
 	}...)
 
-	const message = "test message"
-
 	// If running with "go test -v", print out the log messages as a sanity check.
 	if testing.Verbose() {
 		checkBuf := new(bytes.Buffer)
 		for _, bc := range benchCases {
 			checkBuf.Reset()
-			logger := log.ZeroLogWrapper{Logger: zerolog.New(checkBuf)}
+			zl := zerolog.New(checkBuf)
+			logger := log.ZeroLogWrapper{Logger: &zl}
 			logger.Info(message, bc.keyVals...)
 
 			b.Logf("zero logger output for %s: %s", bc.name, checkBuf.String())
@@ -82,23 +84,8 @@ func BenchmarkLoggers(b *testing.B) {
 		for _, bc := range benchCases {
 			bc := bc
 			b.Run(bc.name, func(b *testing.B) {
-				logger := log.ZeroLogWrapper{Logger: zerolog.New(io.Discard)}
-
-				for i := 0; i < b.N; i++ {
-					logger.Info(message, bc.keyVals...)
-				}
-			})
-		}
-	})
-
-	// zerolog offers a no-op writer.
-	// It appears to be slower than our custom NopLogger,
-	// so include it in the nop benchmarks as a point of reference.
-	b.Run("zerolog nop", func(b *testing.B) {
-		for _, bc := range nopCases {
-			bc := bc
-			b.Run(bc.name, func(b *testing.B) {
-				logger := log.ZeroLogWrapper{Logger: zerolog.Nop()}
+				zl := zerolog.New(io.Discard)
+				logger := log.ZeroLogWrapper{Logger: &zl}
 
 				for i := 0; i < b.N; i++ {
 					logger.Info(message, bc.keyVals...)
@@ -122,3 +109,32 @@ func BenchmarkLoggers(b *testing.B) {
 		}
 	})
 }
+
+func BenchmarkLoggers_StructuredVsFields(b *testing.B) {
+	b.ReportAllocs()
+
+	b.Run("logger structured", func(b *testing.B) {
+		zl := zerolog.New(io.Discard)
+		var logger log.Logger = log.ZeroLogWrapper{Logger: &zl}
+		for i := 0; i < b.N; i++ {
+			logger.Impl().Info().Int64("foo", 100000).Msg(message)
+			logger.Impl().Info().Str("foo", "foo").Msg(message)
+			logger.Impl().Error().
+				Int64("foo", 100000).
+				Str("bar", "foo").
+				Bytes("other", []byte{0xde, 0xad, 0xbe, 0xef}).
+				Err(errors.New("error")).
+				Msg(message)
+		}
+	})
+
+	b.Run("logger", func(b *testing.B) {
+		zl := zerolog.New(io.Discard)
+		var logger log.Logger = log.ZeroLogWrapper{Logger: &zl}
+		for i := 0; i < b.N; i++ {
+			logger.Info(message, "foo", 100000)
+			logger.Info(message, "foo", "foo")
+			logger.Error(message, "foo", 100000, "bar", "foo", "other", []byte{0xde, 0xad, 0xbe, 0xef}, "error", errors.New("error"))
+		}
+	})
+}
diff --git a/log/go.mod b/log/go.mod
@@ -2,16 +2,10 @@ module cosmossdk.io/log
 
 go 1.19
 
-require (
-	github.com/cometbft/cometbft v0.37.0-alpha.3
-	github.com/rs/zerolog v1.29.0
-)
+require github.com/rs/zerolog v1.29.0
 
 require (
-	github.com/go-kit/log v0.2.1 // indirect
-	github.com/go-logfmt/logfmt v0.5.1 // indirect
 	github.com/mattn/go-colorable v0.1.13 // indirect
 	github.com/mattn/go-isatty v0.0.16 // indirect
-	github.com/pkg/errors v0.9.1 // indirect
 	golang.org/x/sys v0.5.0 // indirect
 )
diff --git a/log/go.sum b/log/go.sum
@@ -1,28 +1,17 @@
-github.com/cometbft/cometbft v0.37.0-alpha.3 h1:74F+cMr4pd1a2lFn/h4TxXmO8VWi3A2dxyoMcjlMWuQ=
-github.com/cometbft/cometbft v0.37.0-alpha.3/go.mod h1:dUGbIGYoLM11xUruTTJY4Xp9FHh6Nfu3Nots8/+UNSo=
 github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
-github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
-github.com/go-kit/log v0.2.1 h1:MRVx0/zhvdseW+Gza6N9rVzU/IVzaeE1SFI4raAhmBU=
-github.com/go-kit/log v0.2.1/go.mod h1:NwTd00d/i8cPZ3xOwwiv2PO5MOcx78fFErGNcVmBjv0=
-github.com/go-logfmt/logfmt v0.5.1 h1:otpy5pqBCBZ1ng9RQ0dPu4PN7ba75Y/aA+UpowDyNVA=
-github.com/go-logfmt/logfmt v0.5.1/go.mod h1:WYhtIu8zTZfxdn5+rREduYbwxfcBr/Vr6KEVveWlfTs=
 github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
 github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4=
 github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA=
 github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg=
 github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94=
 github.com/mattn/go-isatty v0.0.16 h1:bq3VjFmv/sOjHtdEhmkEV4x1AJtvUvOJ2PFAZ5+peKQ=
 github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
-github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
 github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
-github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
 github.com/rs/zerolog v1.29.0 h1:Zes4hju04hjbvkVkOhdl2HpZa+0PmVwigmo8XoORE5w=
 github.com/rs/zerolog v1.29.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0=
-github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
 golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.5.0 h1:MUK/U/4lj1t1oPg0HfuXDN/Z1wv31ZJ/YcPiGccS4DU=
 golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
-gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=