refactor(log): associate test logger with testing.T instance (#15261)

baseapp/abci_test.go

@@ -15,6 +15,7 @@ import (
 	"github.com/stretchr/testify/require"
 
 	errorsmod "cosmossdk.io/errors"
+	"cosmossdk.io/log"
 	pruningtypes "cosmossdk.io/store/pruning/types"
 	"cosmossdk.io/store/snapshots"
 	snapshottypes "cosmossdk.io/store/snapshots/types"
@@ -46,7 +47,7 @@ func TestABCI_Info(t *testing.T) {
 func TestABCI_InitChain(t *testing.T) {
 	name := t.Name()
 	db := dbm.NewMemDB()
-	logger := defaultLogger()
+	logger := log.NewTestLogger(t)
 	app := baseapp.NewBaseApp(name, logger, db, nil)
 
 	capKey := storetypes.NewKVStoreKey("main")
@@ -126,8 +127,7 @@ func TestABCI_InitChain(t *testing.T) {
 func TestABCI_InitChain_WithInitialHeight(t *testing.T) {
 	name := t.Name()
 	db := dbm.NewMemDB()
-	logger := defaultLogger()
-	app := baseapp.NewBaseApp(name, logger, db, nil)
+	app := baseapp.NewBaseApp(name, log.NewTestLogger(t), db, nil)
 
 	app.InitChain(
 		abci.RequestInitChain{
@@ -142,8 +142,7 @@ func TestABCI_InitChain_WithInitialHeight(t *testing.T) {
 func TestABCI_BeginBlock_WithInitialHeight(t *testing.T) {
 	name := t.Name()
 	db := dbm.NewMemDB()
-	logger := defaultLogger()
-	app := baseapp.NewBaseApp(name, logger, db, nil)
+	app := baseapp.NewBaseApp(name, log.NewTestLogger(t), db, nil)
 
 	app.InitChain(
 		abci.RequestInitChain{
@@ -566,15 +565,14 @@ func TestABCI_ApplySnapshotChunk(t *testing.T) {
 func TestABCI_EndBlock(t *testing.T) {
 	db := dbm.NewMemDB()
 	name := t.Name()
-	logger := defaultLogger()
 
 	cp := &cmtproto.ConsensusParams{
 		Block: &cmtproto.BlockParams{
 			MaxGas: 5000000,
 		},
 	}
 
-	app := baseapp.NewBaseApp(name, logger, db, nil)
+	app := baseapp.NewBaseApp(name, log.NewTestLogger(t), db, nil)
 	app.SetParamStore(&paramStore{db: dbm.NewMemDB()})
 	app.InitChain(abci.RequestInitChain{
 		ConsensusParams: cp,
@@ -1211,7 +1209,7 @@ func TestABCI_Query(t *testing.T) {
 }
 
 func TestABCI_GetBlockRetentionHeight(t *testing.T) {
-	logger := defaultLogger()
+	logger := log.NewTestLogger(t)
 	db := dbm.NewMemDB()
 	name := t.Name()
 

baseapp/baseapp_test.go

@@ -59,10 +59,9 @@ func NewBaseAppSuite(t *testing.T, opts ...func(*baseapp.BaseApp)) *BaseAppSuite
 	baseapptestutil.RegisterInterfaces(cdc.InterfaceRegistry())
 
 	txConfig := authtx.NewTxConfig(cdc, authtx.DefaultSignModes)
-	logger := defaultLogger()
 	db := dbm.NewMemDB()
 
-	app := baseapp.NewBaseApp(t.Name(), logger, db, txConfig.TxDecoder(), opts...)
+	app := baseapp.NewBaseApp(t.Name(), log.NewTestLogger(t), db, txConfig.TxDecoder(), opts...)
 	require.Equal(t, t.Name(), app.Name())
 
 	app.SetInterfaceRegistry(cdc.InterfaceRegistry())
@@ -159,7 +158,7 @@ func NewBaseAppSuiteWithSnapshots(t *testing.T, cfg SnapshotsConfig, opts ...fun
 }
 
 func TestLoadVersion(t *testing.T) {
-	logger := defaultLogger()
+	logger := log.NewTestLogger(t)
 	pruningOpt := baseapp.SetPruning(pruningtypes.NewPruningOptions(pruningtypes.PruningNothing))
 	db := dbm.NewMemDB()
 	name := t.Name()
@@ -284,7 +283,7 @@ func TestSetLoader(t *testing.T) {
 			if tc.setLoader != nil {
 				opts = append(opts, tc.setLoader)
 			}
-			app := baseapp.NewBaseApp(t.Name(), defaultLogger(), db, nil, opts...)
+			app := baseapp.NewBaseApp(t.Name(), log.NewTestLogger(t), db, nil, opts...)
 			app.MountStores(storetypes.NewKVStoreKey(tc.loadStoreKey))
 			err := app.LoadLatestVersion()
 			require.Nil(t, err)
@@ -302,11 +301,10 @@ func TestSetLoader(t *testing.T) {
 }
 
 func TestVersionSetterGetter(t *testing.T) {
-	logger := defaultLogger()
 	pruningOpt := baseapp.SetPruning(pruningtypes.NewPruningOptions(pruningtypes.PruningDefault))
 	db := dbm.NewMemDB()
 	name := t.Name()
-	app := baseapp.NewBaseApp(name, logger, db, nil, pruningOpt)
+	app := baseapp.NewBaseApp(name, log.NewTestLogger(t), db, nil, pruningOpt)
 
 	require.Equal(t, "", app.Version())
 	res := app.Query(abci.RequestQuery{Path: "app/version"})
@@ -361,9 +359,8 @@ func TestOptionFunction(t *testing.T) {
 		}
 	}
 
-	logger := defaultLogger()
 	db := dbm.NewMemDB()
-	bap := baseapp.NewBaseApp("starting name", logger, db, nil, testChangeNameHelper("new name"))
+	bap := baseapp.NewBaseApp("starting name", log.NewTestLogger(t), db, nil, testChangeNameHelper("new name"))
 	require.Equal(t, bap.Name(), "new name", "BaseApp should have had name changed via option function")
 }
 
@@ -543,10 +540,9 @@ func TestBaseAppAnteHandler(t *testing.T) {
 func TestABCI_CreateQueryContext(t *testing.T) {
 	t.Parallel()
 
-	logger := defaultLogger()
 	db := dbm.NewMemDB()
 	name := t.Name()
-	app := baseapp.NewBaseApp(name, logger, db, nil)
+	app := baseapp.NewBaseApp(name, log.NewTestLogger(t), db, nil)
 
 	app.BeginBlock(abci.RequestBeginBlock{Header: cmtproto.Header{Height: 1}})
 	app.Commit()

baseapp/grpcrouter_test.go

@@ -58,7 +58,7 @@ func TestRegisterQueryServiceTwice(t *testing.T) {
 	err := depinject.Inject(makeMinimalConfig(), &appBuilder)
 	require.NoError(t, err)
 	db := dbm.NewMemDB()
-	app := appBuilder.Build(log.NewLogger(), db, nil)
+	app := appBuilder.Build(log.NewTestLogger(t), db, nil)
 
 	// First time registering service shouldn't panic.
 	require.NotPanics(t, func() {

baseapp/msg_service_router_test.go

@@ -28,7 +28,7 @@ func TestRegisterMsgService(t *testing.T) {
 	)
 	err := depinject.Inject(makeMinimalConfig(), &appBuilder, &registry)
 	require.NoError(t, err)
-	app := appBuilder.Build(log.NewLogger(), dbm.NewMemDB(), nil)
+	app := appBuilder.Build(log.NewTestLogger(t), dbm.NewMemDB(), nil)
 
 	require.Panics(t, func() {
 		testdata.RegisterMsgServer(
@@ -57,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.NewLogger(), db, nil)
+	app := appBuilder.Build(log.NewTestLogger(t), db, nil)
 	testdata.RegisterInterfaces(registry)
 
 	// First time registering service shouldn't panic.

baseapp/utils_test.go

@@ -25,7 +25,6 @@ import (
 	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"
@@ -52,14 +51,6 @@ import (
 
 var ParamStoreKey = []byte("paramstore")
 
-func defaultLogger() log.Logger {
-	if testing.Verbose() {
-		return log.NewLoggerWithKV("module", "baseapp/test")
-	}
-
-	return log.NewNopLogger()
-}
-
 // GenesisStateWithSingleValidator initializes GenesisState with a single validator and genesis accounts
 // that also act as delegators.
 func GenesisStateWithSingleValidator(t *testing.T, codec codec.Codec, builder *runtime.AppBuilder) map[string]json.RawMessage {

go.mod

@@ -154,6 +154,9 @@ require (
 	nhooyr.io/websocket v1.8.6 // indirect
 )
 
+// Short-lived replace for an outstanding PR of log.
+replace cosmossdk.io/log => ./log
+
 // Below are the long-lived replace of the Cosmos SDK
 replace (
 	// use cosmos fork of keyring

log/CHANGELOG.md

@@ -30,3 +30,7 @@ Ref: https://keepachangelog.com/en/1.0.0/
 # Changelog
 
 ## [Unreleased]
+
+### Improvements
+
+- [#15261](https://github.com/cosmos/cosmos-sdk/pull/15261): Provide `log.NewTestLogger(*testing.T)` function to create new log.Logger associated with a test

log/testing.go

@@ -1,20 +1,26 @@
 package log
 
-import "testing"
+import "github.com/rs/zerolog"
 
-// reuse the same logger across all tests
-var _testingLogger Logger
+// TestingT is the interface required for logging in tests.
+// It is a subset of testing.T to avoid a direct dependency on the testing package.
+type TestingT zerolog.TestingLog
 
-func NewTestingLogger() Logger {
-	if _testingLogger != nil {
-		return _testingLogger
+// NewTestLogger returns a logger that calls t.Log to write entries.
+//
+// If the logs may help debug a test failure,
+// you may want to use NewTestLogger(t) in your test.
+// Otherwise, use NewNopLogger().
+func NewTestLogger(t TestingT) Logger {
+	cw := zerolog.NewConsoleWriter()
+	cw.Out = zerolog.TestWriter{
+		T: t,
+		// Normally one would use zerolog.ConsoleTestWriter
+		// to set the option on NewConsoleWriter,
+		// but the zerolog source for that is hardcoded to Frame=6.
+		// With Frame=6, all source locations are printed as "logger.go",
+		// but Frame=7 prints correct source locations.
+		Frame: 7,
 	}
-
-	if testing.Verbose() {
-		_testingLogger = NewLoggerWithKV(ModuleKey, "test")
-	} else {
-		_testingLogger = NewNopLogger()
-	}
-
-	return _testingLogger
+	return NewCustomLogger(zerolog.New(cw))
 }

server/mock/app_test.go

@@ -9,18 +9,30 @@ import (
 	cmtproto "github.com/cometbft/cometbft/proto/tendermint/types"
 	"github.com/stretchr/testify/require"
 
+	"cosmossdk.io/log"
+
 	simtypes "github.com/cosmos/cosmos-sdk/types/simulation"
 	genutiltypes "github.com/cosmos/cosmos-sdk/x/genutil/types"
 )
 
-func TestInitApp(t *testing.T) {
-	app, closer, err := SetupApp()
-	// closer may need to be run, even when error in later stage
-	if closer != nil {
-		defer closer()
-	}
+// SetupApp initializes a new application,
+// failing t if initialization fails.
+func SetupApp(t *testing.T) abci.Application {
+	t.Helper()
+
+	logger := log.NewTestLogger(t)
+
+	rootDir := t.TempDir()
+
+	app, err := NewApp(rootDir, logger)
 	require.NoError(t, err)
 
+	return app
+}
+
+func TestInitApp(t *testing.T) {
+	app := SetupApp(t)
+
 	appState, err := AppGenState(nil, genutiltypes.AppGenesis{}, nil)
 	require.NoError(t, err)
 
@@ -42,12 +54,7 @@ func TestInitApp(t *testing.T) {
 }
 
 func TestDeliverTx(t *testing.T) {
-	app, closer, err := SetupApp()
-	// closer may need to be run, even when error in later stage
-	if closer != nil {
-		defer closer()
-	}
-	require.NoError(t, err)
+	app := SetupApp(t)
 
 	key := "my-special-key"
 	value := "top-secret-data!!"

simapp/app_test.go

@@ -41,9 +41,9 @@ import (
 
 func TestSimAppExportAndBlockedAddrs(t *testing.T) {
 	db := dbm.NewMemDB()
-	logger := log.NewLogger()
+	logger := log.NewTestLogger(t)
 	app := NewSimappWithCustomOptions(t, false, SetupOptions{
-		Logger:  logger,
+		Logger:  logger.With("instance", "first"),
 		DB:      db,
 		AppOpts: simtestutil.NewAppOptionsWithFlagHome(t.TempDir()),
 	})
@@ -66,20 +66,19 @@ func TestSimAppExportAndBlockedAddrs(t *testing.T) {
 
 	app.Commit()
 
-	logger2 := log.NewLogger()
 	// Making a new app object with the db, so that initchain hasn't been called
-	app2 := NewSimApp(logger2, db, nil, true, simtestutil.NewAppOptionsWithFlagHome(t.TempDir()))
+	app2 := NewSimApp(logger.With("instance", "second"), db, nil, true, simtestutil.NewAppOptionsWithFlagHome(t.TempDir()))
 	_, err := app2.ExportAppStateAndValidators(false, []string{}, []string{})
 	require.NoError(t, err, "ExportAppStateAndValidators should not have an error")
 }
 
 func TestRunMigrations(t *testing.T) {
 	db := dbm.NewMemDB()
-	logger := log.NewLogger()
-	app := NewSimApp(logger, db, nil, true, simtestutil.NewAppOptionsWithFlagHome(t.TempDir()))
+	logger := log.NewTestLogger(t)
+	app := NewSimApp(logger.With("instance", "simapp"), db, nil, true, simtestutil.NewAppOptionsWithFlagHome(t.TempDir()))
 
 	// Create a new baseapp and configurator for the purpose of this test.
-	bApp := baseapp.NewBaseApp(app.Name(), logger, db, app.TxConfig().TxDecoder())
+	bApp := baseapp.NewBaseApp(app.Name(), logger.With("instance", "baseapp"), db, app.TxConfig().TxDecoder())
 	bApp.SetCommitMultiStoreTracer(nil)
 	bApp.SetInterfaceRegistry(app.InterfaceRegistry())
 	app.BaseApp = bApp
@@ -216,8 +215,7 @@ func TestRunMigrations(t *testing.T) {
 
 func TestInitGenesisOnMigration(t *testing.T) {
 	db := dbm.NewMemDB()
-	logger := log.NewLogger()
-	app := NewSimApp(logger, db, nil, true, simtestutil.NewAppOptionsWithFlagHome(t.TempDir()))
+	app := NewSimApp(log.NewTestLogger(t), db, nil, true, simtestutil.NewAppOptionsWithFlagHome(t.TempDir()))
 	ctx := app.NewContext(true, cmtproto.Header{Height: app.LastBlockHeight()})
 
 	// Create a mock module. This module will serve as the new module we're
@@ -259,9 +257,8 @@ func TestInitGenesisOnMigration(t *testing.T) {
 
 func TestUpgradeStateOnGenesis(t *testing.T) {
 	db := dbm.NewMemDB()
-	logger := log.NewLogger()
 	app := NewSimappWithCustomOptions(t, false, SetupOptions{
-		Logger:  logger,
+		Logger:  log.NewTestLogger(t),
 		DB:      db,
 		AppOpts: simtestutil.NewAppOptionsWithFlagHome(t.TempDir()),
 	})

simapp/go.mod

@@ -7,7 +7,7 @@ require (
 	cosmossdk.io/client/v2 v2.0.0-20230220152935-67f04e629623
 	cosmossdk.io/core v0.6.0
 	cosmossdk.io/depinject v1.0.0-alpha.3
-	cosmossdk.io/log v0.0.0-20230227204852-3535ee51c728
+	cosmossdk.io/log v0.0.0-20230303183710-74c894f12720
 	cosmossdk.io/math v1.0.0-beta.6.0.20230216172121-959ce49135e4
 	cosmossdk.io/store v0.0.0-20230227103508-bbe7f8a11b44
 	cosmossdk.io/tools/confix v0.0.0-20230120150717-4f6f6c00021f

simapp/go.sum

@@ -200,8 +200,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-20230227204852-3535ee51c728 h1:OpmiiO3x9esYawh4WX7jLL0UzBoOfjZrx3SdM3l8lhE=
-cosmossdk.io/log v0.0.0-20230227204852-3535ee51c728/go.mod h1:FZRNfYm6Jgp+toyDR8Ek1qrmNjdsDddEQnfATMbpGYg=
+cosmossdk.io/log v0.0.0-20230303183710-74c894f12720 h1:yrSwsgagxMHe/cj5V0TRRxNyr1k1cshizqaOGU4McKE=
+cosmossdk.io/log v0.0.0-20230303183710-74c894f12720/go.mod h1:ilL9YXutMQo36MS9CD1cFNUqqHadAtyf8+A2b2EqO5A=
 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-20230227103508-bbe7f8a11b44 h1:/pKsj/ApzO4+zMwpgLiPG5iakoHxziGpMiJcz4S+r4w=