feat: verbose logging during upgrades (#24720)

Co-authored-by: Alex | Interchain Labs <alex@interchainlabs.io>

CHANGELOG.md

@@ -38,6 +38,9 @@ Ref: https://keepachangelog.com/en/1.0.0/
 
 ## [Unreleased]
 
+### Features
+* (server) [#24720](https://github.com/cosmos/cosmos-sdk/pull/24720) add `verbose_log_level` flag for configuring the log level when switching to verbose logging mode during sensitive operations (such as chain upgrades).
+
 ### Improvements
 
 * (baseapp) [#24655](https://github.com/cosmos/cosmos-sdk/pull/24655) Add mutex locks for `state` and make `lastCommitInfo` atomic to prevent race conditions between `Commit` and `CreateQueryContext`.

client/flags/flags.go

@@ -87,9 +87,10 @@ const (
 	// This differs from FlagOutputDocument that is used to set the output file.
 	FlagOutput = "output"
 	// Logging flags
-	FlagLogLevel   = "log_level"
-	FlagLogFormat  = "log_format"
-	FlagLogNoColor = "log_no_color"
+	FlagLogLevel        = "log_level"
+	FlagVerboseLogLevel = "verbose_log_level"
+	FlagLogFormat       = "log_format"
+	FlagLogNoColor      = "log_no_color"
 )
 
 // List of supported output formats

go.mod

@@ -216,9 +216,7 @@ require (
 
 // Here are the short-lived replace from the Cosmos SDK
 // Replace here are pending PRs, or version to be tagged
-// replace (
-// 	<temporary replace>
-// )
+replace cosmossdk.io/log => ./log
 
 // Replace all unreleased direct deps upgraded to comet v1
 replace (

go.sum

@@ -620,8 +620,6 @@ cosmossdk.io/depinject v1.2.0 h1:6NW/FSK1IkWTrX7XxUpBmX1QMBozpEI9SsWkKTBc5zw=
 cosmossdk.io/depinject v1.2.0/go.mod h1:pvitjtUxZZZTQESKNS9KhGjWVslJZxtO9VooRJYyPjk=
 cosmossdk.io/errors v1.0.2 h1:wcYiJz08HThbWxd/L4jObeLaLySopyyuUFB5w4AGpCo=
 cosmossdk.io/errors v1.0.2/go.mod h1:0rjgiHkftRYPj//3DrD6y8hcm40HcPv/dR4R/4efr0k=
-cosmossdk.io/log v1.5.1 h1:wLwiYXmfrort/O+j6EkjF+HvbdrRQd+4cYCPKFSm+zM=
-cosmossdk.io/log v1.5.1/go.mod h1:5cXXBvfBkR2/BcXmosdCSLXllvgSjphrrDVdfVRmBGM=
 cosmossdk.io/math v1.5.3 h1:WH6tu6Z3AUCeHbeOSHg2mt9rnoiUWVWaQ2t6Gkll96U=
 cosmossdk.io/math v1.5.3/go.mod h1:uqcZv7vexnhMFJF+6zh9EWdm/+Ylyln34IvPnBauPCQ=
 cosmossdk.io/schema v1.1.0 h1:mmpuz3dzouCoyjjcMcA/xHBEmMChN+EHh8EHxHRHhzE=

log/CHANGELOG.md

@@ -22,6 +22,8 @@ Each entry must include the Github issue reference in the following format:
 
 ## [Unreleased]
 
+* [#24720](https://github.com/cosmos/cosmos-sdk/pull/24720) add `VerboseModeLogger` extension interface and `VerboseLevel` configuration option for increasing log verbosity during sensitive operations such as upgrades.
+
 ## [v1.5.1](https://github.com/cosmos/cosmos-sdk/releases/tag/log/v1.5.1) - 2025-03-07
 
 * [#23928](https://github.com/cosmos/cosmos-sdk/pull/23928) Bump sonic json library to [v1.3.1](https://github.com/bytedance/sonic/releases/tag/v1.13.1) for Go 1.24 compatibility.

log/level_test.go

@@ -1,8 +1,12 @@
 package log_test
 
 import (
+	"bytes"
+	"fmt"
 	"testing"
 
+	"github.com/rs/zerolog"
+
 	"cosmossdk.io/log"
 )
 
@@ -88,3 +92,128 @@ func TestParseLogLevel(t *testing.T) {
 		t.Errorf("expected filter to return true for state:debug")
 	}
 }
+
+func TestVerboseMode(t *testing.T) {
+	logMessages := []struct {
+		level   zerolog.Level
+		module  string
+		message string
+	}{
+		{
+			zerolog.InfoLevel,
+			"foo",
+			"msg 1",
+		},
+		{
+			zerolog.WarnLevel,
+			"foo",
+			"msg 2",
+		},
+		{
+			zerolog.ErrorLevel,
+			"bar",
+			"msg 3",
+		},
+		{
+			zerolog.DebugLevel,
+			"foo",
+			"msg 4",
+		},
+	}
+	tt := []struct {
+		name         string
+		level        zerolog.Level
+		verboseLevel zerolog.Level
+		filter       string
+		expected     string
+	}{
+		{
+			name:         "verbose mode simple case",
+			level:        zerolog.WarnLevel,
+			verboseLevel: zerolog.DebugLevel,
+			expected: `* WRN msg 2 module=foo
+* ERR msg 3 module=bar
+* ERR Start Verbose Mode
+* INF msg 1 module=foo
+* WRN msg 2 module=foo
+* ERR msg 3 module=bar
+* DBG msg 4 module=foo
+`,
+		},
+		{
+			name:         "verbose mode with filter",
+			level:        zerolog.WarnLevel,
+			verboseLevel: zerolog.InfoLevel,
+			filter:       "foo:error",
+			expected: `* ERR msg 3 module=bar
+* ERR Start Verbose Mode
+* INF msg 1 module=foo
+* WRN msg 2 module=foo
+* ERR msg 3 module=bar
+`,
+		},
+		{
+			name:         "no verbose mode",
+			level:        zerolog.WarnLevel,
+			verboseLevel: zerolog.NoLevel,
+			expected: `* WRN msg 2 module=foo
+* ERR msg 3 module=bar
+* ERR Start Verbose Mode
+* WRN msg 2 module=foo
+* ERR msg 3 module=bar
+`,
+		},
+		{
+			name:         "no verbose mode with filter",
+			level:        zerolog.WarnLevel,
+			verboseLevel: zerolog.NoLevel,
+			filter:       "foo:error",
+			expected: `* ERR msg 3 module=bar
+* ERR Start Verbose Mode
+* ERR msg 3 module=bar
+`,
+		},
+	}
+	for i, tc := range tt {
+		t.Run(fmt.Sprintf("%d: %s", i, tc.name), func(t *testing.T) {
+			out := new(bytes.Buffer)
+			opts := []log.Option{
+				log.LevelOption(tc.level),
+				log.VerboseLevelOption(tc.verboseLevel),
+				log.ColorOption(false),
+				log.TimeFormatOption("*"), // disable non-deterministic time format
+			}
+			if tc.filter != "" {
+				filter, err := log.ParseLogLevel(tc.filter)
+				if err != nil {
+					t.Fatalf("failed to parse log level: %v", err)
+				}
+				opts = append(opts, log.FilterOption(filter))
+			}
+			logger := log.NewLogger(out, opts...)
+			writeMsgs := func() {
+				for _, msg := range logMessages {
+					switch msg.level {
+					case zerolog.InfoLevel:
+						logger.Info(msg.message, log.ModuleKey, msg.module)
+					case zerolog.WarnLevel:
+						logger.Warn(msg.message, log.ModuleKey, msg.module)
+					case zerolog.DebugLevel:
+						logger.Debug(msg.message, log.ModuleKey, msg.module)
+					case zerolog.ErrorLevel:
+						logger.Error(msg.message, log.ModuleKey, msg.module)
+					default:
+						t.Fatalf("unexpected level: %v", msg.level)
+					}
+				}
+			}
+			writeMsgs()
+			logger.Error("Start Verbose Mode")
+			logger.(log.VerboseModeLogger).SetVerboseMode(true)
+			writeMsgs()
+			if tc.expected != out.String() {
+				t.Fatalf("expected:\n%s\ngot:\n%s", tc.expected, out.String())
+			}
+		})
+	}
+}

log/logger.go

@@ -62,6 +62,15 @@ type Logger interface {
 	Impl() any
 }
 
+// VerboseModeLogger is an extension interface of Logger which allows verbosity to be configured.
+type VerboseModeLogger interface {
+	Logger
+	// SetVerboseMode configures whether the logger enters verbose mode or not for
+	// special operations where increased observability of log messages is desired
+	// (such as chain upgrades).
+	SetVerboseMode(bool)
+}
+
 // WithJSONMarshal configures zerolog global json encoding.
 func WithJSONMarshal(marshaler func(v any) ([]byte, error)) {
 	zerolog.InterfaceMarshalFunc = func(i any) ([]byte, error) {
@@ -80,6 +89,11 @@ func WithJSONMarshal(marshaler func(v any) ([]byte, error)) {
 
 type zeroLogWrapper struct {
 	*zerolog.Logger
+	regularLevel zerolog.Level
+	verboseLevel zerolog.Level
+	// this field is used to disable filtering during verbose logging
+	// and will only be non-nil when we have a filterWriter
+	filterWriter *filterWriter
 }
 
 // NewLogger returns a new logger that writes to the given destination.
@@ -105,8 +119,13 @@ func NewLogger(dst io.Writer, options ...Option) Logger {
 		}
 	}
 
+	var fltWtr *filterWriter
 	if logCfg.Filter != nil {
-		output = NewFilterWriter(output, logCfg.Filter)
+		fltWtr = &filterWriter{
+			parent: output,
+			filter: logCfg.Filter,
+		}
+		output = fltWtr
 	}
 
 	logger := zerolog.New(output)
@@ -123,18 +142,25 @@ func NewLogger(dst io.Writer, options ...Option) Logger {
 		logger = logger.With().Timestamp().Logger()
 	}
 
-	if logCfg.Level != zerolog.NoLevel {
-		logger = logger.Level(logCfg.Level)
-	}
-
+	logger = logger.Level(logCfg.Level)
 	logger = logger.Hook(logCfg.Hooks...)
 
-	return zeroLogWrapper{&logger}
+	return zeroLogWrapper{
+		Logger:       &logger,
+		regularLevel: logCfg.Level,
+		verboseLevel: logCfg.VerboseLevel,
+		filterWriter: fltWtr,
+	}
 }
 
 // NewCustomLogger returns a new logger with the given zerolog logger.
 func NewCustomLogger(logger zerolog.Logger) Logger {
-	return zeroLogWrapper{&logger}
+	return zeroLogWrapper{
+		Logger:       &logger,
+		regularLevel: logger.GetLevel(),
+		verboseLevel: zerolog.NoLevel,
+		filterWriter: nil,
+	}
 }
 
 // Info takes a message and a set of key/value pairs and logs with level INFO.
@@ -164,13 +190,15 @@ func (l zeroLogWrapper) Debug(msg string, keyVals ...interface{}) {
 // With returns a new wrapped logger with additional context provided by a set.
 func (l zeroLogWrapper) With(keyVals ...interface{}) Logger {
 	logger := l.Logger.With().Fields(keyVals).Logger()
-	return zeroLogWrapper{&logger}
+	l.Logger = &logger
+	return l
 }
 
 // WithContext returns a new wrapped logger with additional context provided by a set.
 func (l zeroLogWrapper) WithContext(keyVals ...interface{}) any {
 	logger := l.Logger.With().Fields(keyVals).Logger()
-	return zeroLogWrapper{&logger}
+	l.Logger = &logger
+	return l
 }
 
 // Impl returns the underlying zerolog logger.
@@ -179,6 +207,23 @@ func (l zeroLogWrapper) Impl() interface{} {
 	return l.Logger
 }
 
+// SetVerboseMode implements VerboseModeLogger interface.
+func (l zeroLogWrapper) SetVerboseMode(enable bool) {
+	if enable && l.verboseLevel != zerolog.NoLevel {
+		*l.Logger = l.Level(l.verboseLevel)
+		if l.filterWriter != nil {
+			l.filterWriter.disableFilter = true
+		}
+	} else {
+		*l.Logger = l.Level(l.regularLevel)
+		if l.filterWriter != nil {
+			l.filterWriter.disableFilter = false
+		}
+	}
+}
+
+var _ VerboseModeLogger = zeroLogWrapper{}
+
 // NewNopLogger returns a new logger that does nothing.
 func NewNopLogger() Logger {
 	// The custom nopLogger is about 3x faster than a zeroLogWrapper with zerolog.Nop().

log/options.go

@@ -8,7 +8,7 @@ import (
 
 // defaultConfig has all the options disabled, except Color and TimeFormat
 var defaultConfig = Config{
-	Level:      zerolog.NoLevel,
+	Level:      zerolog.TraceLevel, // this is the default level that zerolog initializes new Logger's with
 	Filter:     nil,
 	OutputJSON: false,
 	Color:      true,
@@ -19,7 +19,16 @@ var defaultConfig = Config{
 
 // Config defines configuration for the logger.
 type Config struct {
-	Level      zerolog.Level
+	// Level is the default logging level.
+	Level zerolog.Level
+	// VerboseLevel is the logging level to use when verbose mode is enabled.
+	// If there is a filter enabled, it will be disabled when verbose mode is enabled
+	// and all log messages will be emitted at the VerboseLevel.
+	// If this is set to NoLevel, then no changes to the logging level or filter will be made
+	// when verbose mode is enabled.
+	VerboseLevel zerolog.Level
+	// Filter is the filter function to use that allows for filtering by key and level.
+	// When verbose mode is enabled, the filter will be disabled unless VerboseLevel is set to NoLevel.
 	Filter     FilterFunc
 	OutputJSON bool
 	Color      bool
@@ -45,6 +54,14 @@ func LevelOption(level zerolog.Level) Option {
 	}
 }
 
+// VerboseLevelOption sets the verbose level for the Logger.
+// When verbose mode is enabled, the logger will be switched to this level.
+func VerboseLevelOption(level zerolog.Level) Option {
+	return func(cfg *Config) {
+		cfg.VerboseLevel = level
+	}
+}
+
 // OutputJSONOption sets the output of the logger to JSON.
 // By default, the logger outputs to a human-readable format.
 func OutputJSONOption() Option {

log/with_test.go

@@ -0,0 +1,46 @@
+package log
+
+import (
+	"bytes"
+	"testing"
+
+	"github.com/rs/zerolog"
+)
+
+// this test ensures that when the With and WithContext methods are called,
+// that the log wrapper is properly copied with all of its associated options
+// otherwise, verbose mode will fail
+func TestLoggerWith(t *testing.T) {
+	logger := zerolog.New(&bytes.Buffer{})
+	regularLevel := zerolog.WarnLevel
+	verboseLevel := zerolog.InfoLevel
+	filterWriter := &filterWriter{}
+	wrapper := zeroLogWrapper{
+		Logger:       &logger,
+		regularLevel: regularLevel,
+		verboseLevel: verboseLevel,
+		filterWriter: filterWriter,
+	}
+
+	wrapper2 := wrapper.With("x", "y").(zeroLogWrapper)
+	if wrapper2.filterWriter != filterWriter {
+		t.Fatalf("expected filterWriter to be copied, but it was not")
+	}
+	if wrapper2.regularLevel != regularLevel {
+		t.Fatalf("expected regularLevel to be copied, but it was not")
+	}
+	if wrapper2.verboseLevel != verboseLevel {
+		t.Fatalf("expected verboseLevel to be copied, but it was not")
+	}
+
+	wrapper3 := wrapper.WithContext("a", "b").(zeroLogWrapper)
+	if wrapper3.filterWriter != filterWriter {
+		t.Fatalf("expected filterWriter to be copied, but it was not")
+	}
+	if wrapper3.regularLevel != regularLevel {
+		t.Fatalf("expected regularLevel to be copied, but it was not")
+	}
+	if wrapper3.verboseLevel != verboseLevel {
+		t.Fatalf("expected verboseLevel to be copied, but it was not")
+	}
+}

log/writer.go

@@ -11,16 +11,17 @@ import (
 // If the filter is nil, the writer will pass all events through.
 // The filter function is called with the module and level of the event.
 func NewFilterWriter(parent io.Writer, filter FilterFunc) io.Writer {
-	return &filterWriter{parent, filter}
+	return &filterWriter{parent: parent, filter: filter}
 }
 
 type filterWriter struct {
-	parent io.Writer
-	filter FilterFunc
+	parent        io.Writer
+	filter        FilterFunc
+	disableFilter bool
 }
 
 func (fw *filterWriter) Write(p []byte) (n int, err error) {
-	if fw.filter == nil {
+	if fw.filter == nil || fw.disableFilter {
 		return fw.parent.Write(p)
 	}
 

server/cmd/execute.go

@@ -29,6 +29,7 @@ func Execute(rootCmd *cobra.Command, envPrefix, defaultHome string) error {
 	// NOTE: The default logger is only checking for the "json" value, any other value will default to plain text.
 	rootCmd.PersistentFlags().String(flags.FlagLogFormat, "plain", "The logging format (json|plain)")
 	rootCmd.PersistentFlags().Bool(flags.FlagLogNoColor, false, "Disable colored logs")
+	rootCmd.PersistentFlags().String(flags.FlagVerboseLogLevel, zerolog.DebugLevel.String(), "The logging level (trace|debug|info|warn|error|fatal|panic|disabled|none) to use when performing operations which require extra verbosity (such as upgrades). When enabled, verbose mode disables any custom log filters. Set this to none to make verbose mode equivalent to normal logging.")
 
 	executor := cmtcli.PrepareBaseCmd(rootCmd, envPrefix, defaultHome)
 	return executor.ExecuteContext(ctx)

server/util.go

@@ -177,6 +177,15 @@ func CreateSDKLogger(ctx *Context, out io.Writer) (log.Logger, error) {
 		// We use CometBFT flag (cmtcli.TraceFlag) for trace logging.
 		log.TraceOption(ctx.Viper.GetBool(FlagTrace)))
 
+	verboseLogLevelStr := ctx.Viper.GetString(flags.FlagVerboseLogLevel)
+	if verboseLogLevelStr != "" {
+		verboseLogLvl, err := parseVerboseLogLevel(verboseLogLevelStr)
+		if err != nil {
+			return nil, fmt.Errorf("invalid verbose log level: %s: %w", verboseLogLevelStr, err)
+		}
+		opts = append(opts, log.VerboseLevelOption(verboseLogLvl))
+	}
+
 	// check and set filter level or keys for the logger if any
 	logLvlStr := ctx.Viper.GetString(flags.FlagLogLevel)
 	if logLvlStr == "" {
@@ -200,6 +209,14 @@ func CreateSDKLogger(ctx *Context, out io.Writer) (log.Logger, error) {
 	return log.NewLogger(out, opts...), nil
 }
 
+// parseVerboseLogLevel parses the string "none" as zerolog.NoLevel and all other level strings using zerolog.ParseLevel.
+func parseVerboseLogLevel(verboseLogLevelStr string) (zerolog.Level, error) {
+	if verboseLogLevelStr == "none" {
+		return zerolog.NoLevel, nil
+	}
+	return zerolog.ParseLevel(verboseLogLevelStr)
+}
+
 // GetServerContextFromCmd returns a Context from a command or an empty Context
 // if it has not been set.
 func GetServerContextFromCmd(cmd *cobra.Command) *Context {

server/verbose_level_test.go

@@ -0,0 +1,32 @@
+package server
+
+import (
+	"testing"
+
+	"github.com/rs/zerolog"
+	"github.com/stretchr/testify/require"
+)
+
+func TestParseVerboseLogLevel(t *testing.T) {
+	tt := []struct {
+		input    string
+		expected zerolog.Level
+	}{
+		// mainly testing that none maps to NoLevel, but checking other cases too for sanity
+		{"none", zerolog.NoLevel},
+		{"debug", zerolog.DebugLevel},
+		{"info", zerolog.InfoLevel},
+		{"warn", zerolog.WarnLevel},
+		{"error", zerolog.ErrorLevel},
+		{"fatal", zerolog.FatalLevel},
+		{"panic", zerolog.PanicLevel},
+		{"trace", zerolog.TraceLevel},
+		{"disabled", zerolog.Disabled},
+	}
+
+	for _, tc := range tt {
+		lvl, err := parseVerboseLogLevel(tc.input)
+		require.NoError(t, err)
+		require.Equal(t, tc.expected, lvl)
+	}
+}

simapp/go.mod

@@ -218,9 +218,8 @@ require (
 
 // Here are the short-lived replace from the SimApp
 // Replace here are pending PRs, or version to be tagged
-// replace (
 // 	<temporary replace>
-// )
+replace cosmossdk.io/log => ../log
 
 // Replace all unreleased direct deps upgraded to comet v1
 replace (

simapp/go.sum

@@ -620,8 +620,6 @@ cosmossdk.io/depinject v1.2.0 h1:6NW/FSK1IkWTrX7XxUpBmX1QMBozpEI9SsWkKTBc5zw=
 cosmossdk.io/depinject v1.2.0/go.mod h1:pvitjtUxZZZTQESKNS9KhGjWVslJZxtO9VooRJYyPjk=
 cosmossdk.io/errors v1.0.2 h1:wcYiJz08HThbWxd/L4jObeLaLySopyyuUFB5w4AGpCo=
 cosmossdk.io/errors v1.0.2/go.mod h1:0rjgiHkftRYPj//3DrD6y8hcm40HcPv/dR4R/4efr0k=
-cosmossdk.io/log v1.5.1 h1:wLwiYXmfrort/O+j6EkjF+HvbdrRQd+4cYCPKFSm+zM=
-cosmossdk.io/log v1.5.1/go.mod h1:5cXXBvfBkR2/BcXmosdCSLXllvgSjphrrDVdfVRmBGM=
 cosmossdk.io/math v1.5.3 h1:WH6tu6Z3AUCeHbeOSHg2mt9rnoiUWVWaQ2t6Gkll96U=
 cosmossdk.io/math v1.5.3/go.mod h1:uqcZv7vexnhMFJF+6zh9EWdm/+Ylyln34IvPnBauPCQ=
 cosmossdk.io/schema v1.1.0 h1:mmpuz3dzouCoyjjcMcA/xHBEmMChN+EHh8EHxHRHhzE=

simapp/upgrades.go

@@ -5,6 +5,7 @@ import (
 
 	storetypes "cosmossdk.io/store/types"
 
+	sdk "github.com/cosmos/cosmos-sdk/types"
 	"github.com/cosmos/cosmos-sdk/types/module"
 	epochstypes "github.com/cosmos/cosmos-sdk/x/epochs/types"
 	protocolpooltypes "github.com/cosmos/cosmos-sdk/x/protocolpool/types"
@@ -23,6 +24,7 @@ func (app SimApp) RegisterUpgradeHandlers() {
 	app.UpgradeKeeper.SetUpgradeHandler(
 		UpgradeName,
 		func(ctx context.Context, _ upgradetypes.Plan, fromVM module.VersionMap) (module.VersionMap, error) {
+			sdk.UnwrapSDKContext(ctx).Logger().Debug("this is a debug level message to test that verbose logging mode has properly been enabled during a chain upgrade")
 			return app.ModuleManager.RunMigrations(ctx, app.Configurator(), fromVM)
 		},
 	)

systemtests/go.mod

@@ -170,6 +170,7 @@ replace github.com/cosmos/cosmos-sdk => ../.
 replace (
 	cosmossdk.io/api => ../api
 	cosmossdk.io/core => ../core
+	cosmossdk.io/log => ../log
 	cosmossdk.io/store => ../store
 	cosmossdk.io/x/tx => ../x/tx
 )

systemtests/go.sum

@@ -6,8 +6,6 @@ cosmossdk.io/depinject v1.2.0 h1:6NW/FSK1IkWTrX7XxUpBmX1QMBozpEI9SsWkKTBc5zw=
 cosmossdk.io/depinject v1.2.0/go.mod h1:pvitjtUxZZZTQESKNS9KhGjWVslJZxtO9VooRJYyPjk=
 cosmossdk.io/errors v1.0.2 h1:wcYiJz08HThbWxd/L4jObeLaLySopyyuUFB5w4AGpCo=
 cosmossdk.io/errors v1.0.2/go.mod h1:0rjgiHkftRYPj//3DrD6y8hcm40HcPv/dR4R/4efr0k=
-cosmossdk.io/log v1.5.1 h1:wLwiYXmfrort/O+j6EkjF+HvbdrRQd+4cYCPKFSm+zM=
-cosmossdk.io/log v1.5.1/go.mod h1:5cXXBvfBkR2/BcXmosdCSLXllvgSjphrrDVdfVRmBGM=
 cosmossdk.io/math v1.5.3 h1:WH6tu6Z3AUCeHbeOSHg2mt9rnoiUWVWaQ2t6Gkll96U=
 cosmossdk.io/math v1.5.3/go.mod h1:uqcZv7vexnhMFJF+6zh9EWdm/+Ylyln34IvPnBauPCQ=
 cosmossdk.io/schema v1.1.0 h1:mmpuz3dzouCoyjjcMcA/xHBEmMChN+EHh8EHxHRHhzE=

systemtests/system.go

@@ -207,7 +207,7 @@ func (s *SystemUnderTest) IsDirty() bool {
 
 // watchLogs stores stdout/stderr in a file and in a ring buffer to output the last n lines on test error
 func (s *SystemUnderTest) watchLogs(node int, cmd *exec.Cmd) {
-	logfile, err := os.Create(filepath.Join(WorkDir, s.outputDir, fmt.Sprintf("node%d.out", node)))
+	logfile, err := os.Create(s.logfileName(node))
 	if err != nil {
 		panic(fmt.Sprintf("open logfile error %#+v", err))
 	}
@@ -230,6 +230,10 @@ func (s *SystemUnderTest) watchLogs(node int, cmd *exec.Cmd) {
 	})
 }
 
+func (s *SystemUnderTest) logfileName(node int) string {
+	return filepath.Join(WorkDir, s.outputDir, fmt.Sprintf("node%d.out", node))
+}
+
 func appendToBuf(r io.Reader, b *ring.Ring, stop <-chan struct{}) {
 	scanner := bufio.NewScanner(r)
 	for scanner.Scan() {
@@ -791,6 +795,24 @@ func (s *SystemUnderTest) BlockTime() time.Duration {
 	return s.blockTime
 }
 
+// FindLogMessage searches the logs of each node and returns a count of the number of
+// nodes that had a match for the provided regular expression.
+func (s *SystemUnderTest) FindLogMessage(regex *regexp.Regexp) int {
+	found := 0
+	for i := 0; i < s.nodesCount; i++ {
+		logfile := s.logfileName(i)
+		content, err := os.ReadFile(logfile)
+		if err != nil {
+			continue // skip if file cannot be read
+		}
+		if regex.Match(content) {
+			found++
+		}
+
+	}
+	return found
+}
+
 type Node struct {
 	ID      string
 	IP      string

tests/go.mod

@@ -221,6 +221,7 @@ require (
 replace (
 	cosmossdk.io/api => ../api
 	cosmossdk.io/core => ../core
+	cosmossdk.io/log => ../log
 	cosmossdk.io/store => ../store
 	cosmossdk.io/x/tx => ../x/tx
 )

tests/go.sum

@@ -622,8 +622,6 @@ cosmossdk.io/depinject v1.2.0 h1:6NW/FSK1IkWTrX7XxUpBmX1QMBozpEI9SsWkKTBc5zw=
 cosmossdk.io/depinject v1.2.0/go.mod h1:pvitjtUxZZZTQESKNS9KhGjWVslJZxtO9VooRJYyPjk=
 cosmossdk.io/errors v1.0.2 h1:wcYiJz08HThbWxd/L4jObeLaLySopyyuUFB5w4AGpCo=
 cosmossdk.io/errors v1.0.2/go.mod h1:0rjgiHkftRYPj//3DrD6y8hcm40HcPv/dR4R/4efr0k=
-cosmossdk.io/log v1.5.1 h1:wLwiYXmfrort/O+j6EkjF+HvbdrRQd+4cYCPKFSm+zM=
-cosmossdk.io/log v1.5.1/go.mod h1:5cXXBvfBkR2/BcXmosdCSLXllvgSjphrrDVdfVRmBGM=
 cosmossdk.io/math v1.5.3 h1:WH6tu6Z3AUCeHbeOSHg2mt9rnoiUWVWaQ2t6Gkll96U=
 cosmossdk.io/math v1.5.3/go.mod h1:uqcZv7vexnhMFJF+6zh9EWdm/+Ylyln34IvPnBauPCQ=
 cosmossdk.io/schema v1.1.0 h1:mmpuz3dzouCoyjjcMcA/xHBEmMChN+EHh8EHxHRHhzE=

tests/systemtests/go.mod

@@ -3,6 +3,7 @@ module cosmossdk.io/tests/systemtests
 go 1.23.5
 
 replace (
+	cosmossdk.io/log => ../../log
 	// always use latest versions in tests
 	cosmossdk.io/systemtests => ../../systemtests
 	github.com/cosmos/cosmos-sdk => ../..

tests/systemtests/go.sum

@@ -6,8 +6,6 @@ cosmossdk.io/depinject v1.2.0 h1:6NW/FSK1IkWTrX7XxUpBmX1QMBozpEI9SsWkKTBc5zw=
 cosmossdk.io/depinject v1.2.0/go.mod h1:pvitjtUxZZZTQESKNS9KhGjWVslJZxtO9VooRJYyPjk=
 cosmossdk.io/errors v1.0.2 h1:wcYiJz08HThbWxd/L4jObeLaLySopyyuUFB5w4AGpCo=
 cosmossdk.io/errors v1.0.2/go.mod h1:0rjgiHkftRYPj//3DrD6y8hcm40HcPv/dR4R/4efr0k=
-cosmossdk.io/log v1.5.1 h1:wLwiYXmfrort/O+j6EkjF+HvbdrRQd+4cYCPKFSm+zM=
-cosmossdk.io/log v1.5.1/go.mod h1:5cXXBvfBkR2/BcXmosdCSLXllvgSjphrrDVdfVRmBGM=
 cosmossdk.io/math v1.5.3 h1:WH6tu6Z3AUCeHbeOSHg2mt9rnoiUWVWaQ2t6Gkll96U=
 cosmossdk.io/math v1.5.3/go.mod h1:uqcZv7vexnhMFJF+6zh9EWdm/+Ylyln34IvPnBauPCQ=
 cosmossdk.io/schema v1.1.0 h1:mmpuz3dzouCoyjjcMcA/xHBEmMChN+EHh8EHxHRHhzE=

tests/systemtests/upgrade_test.go

@@ -4,6 +4,7 @@ package systemtests
 
 import (
 	"fmt"
+	"regexp"
 	"testing"
 	"time"
 
@@ -125,6 +126,10 @@ func TestChainUpgrade(t *testing.T) {
 
 	require.Equal(t, upgradeHeight+1, systest.Sut.CurrentHeight())
 
+	regex, err := regexp.Compile("DBG this is a debug level message to test that verbose logging mode has properly been enabled during a chain upgrade")
+	require.NoError(t, err)
+	require.Equal(t, systest.Sut.NodesCount(), systest.Sut.FindLogMessage(regex))
+
 	// smoke test that new version runs
 	cli = systest.NewCLIWrapper(t, systest.Sut, systest.Verbose)
 	got := cli.Run("tx", "protocolpool", "fund-community-pool", "100stake", "--from=node0")

types/module/module.go

@@ -722,6 +722,7 @@ func (m Manager) RunMigrations(ctx context.Context, cfg Configurator, fromVM Ver
 		// 2. An existing chain is upgrading from version < 0.43 to v0.43+ for the first time.
 		// In this case, all modules have yet to be added to x/upgrade's VersionMap store.
 		if exists {
+			sdkCtx.Logger().Info(fmt.Sprintf("running migrations for module: %s", moduleName))
 			err := c.runModuleMigrations(sdkCtx, moduleName, fromVersion, toVersion)
 			if err != nil {
 				return nil, err

x/upgrade/CHANGELOG.md

@@ -28,6 +28,8 @@ Ref: https://keepachangelog.com/en/1.0.0/
 ### Improvements
 
 * [#24543](https://github.com/cosmos/cosmos-sdk/issues/24543) Use `telemetry.MetricKeyPreBlocker` metric key instead of `telemetry.MetricKeyBeginBlocker` in `PreBlocker`.
+* [#24720](https://github.com/cosmos/cosmos-sdk/pull/24720) switch to verbose mode logging when calling upgrading handlers.
+
 
 ## [v0.2.0](https://github.com/cosmos/cosmos-sdk/releases/tag/x/upgrade/v0.2.0) - 2025-04-24
 

x/upgrade/keeper/keeper.go

@@ -463,11 +463,25 @@ func (k Keeper) ApplyUpgrade(ctx context.Context, plan types.Plan) error {
 		return err
 	}
 
+	// Enable verbose mode logging, if possible
+	sdkCtx := sdk.UnwrapSDKContext(ctx)
+	logger := sdkCtx.Logger()
+	if verboseLogger, ok := logger.(log.VerboseModeLogger); ok {
+		verboseLogger.SetVerboseMode(true)
+	}
+
+	logger.Info("Starting upgrade", "name", plan.Name, "height", plan.Height)
+
 	updatedVM, err := handler(ctx, plan, vm)
 	if err != nil {
 		return err
 	}
 
+	// Disable verbose mode logging
+	if verboseLogger, ok := logger.(log.VerboseModeLogger); ok {
+		verboseLogger.SetVerboseMode(false)
+	}
+
 	err = k.SetModuleVersionMap(ctx, updatedVM)
 	if err != nil {
 		return err