log,kwild: allow increase log thresh on child loggers

cmd/kwil-admin/nodecfg/toml.go

@@ -77,6 +77,15 @@ const defaultConfigTemplate = `
 # Output level for logging, default is "info". Other options are "debug", "error", "warn", "trace"
 level = "{{ .Logging.Level }}"
 
+# RPC systems' logging level. Must be higher than log.level.
+rpc_level = "{{ .Logging.RPCLevel }}"
+
+# Consensus engine's logging level. Must be higher than log.level.
+consensus_level = "{{ .Logging.ConsensusLevel }}"
+
+# DB driver's logging level. Must be higher than log.level.
+db_level = "{{ .Logging.DBLevel }}"
+
 # Output paths for the logger, can be stdout or a file path
 output_paths = {{arrayFormatter .Logging.OutputPaths }}
 

cmd/kwild/config/config.go

@@ -41,10 +41,13 @@ type KwildConfig struct {
 }
 
 type Logging struct {
-	Level        string   `mapstructure:"level"`
-	Format       string   `mapstructure:"format"`
-	TimeEncoding string   `mapstructure:"time_format"`
-	OutputPaths  []string `mapstructure:"output_paths"`
+	Level          string   `mapstructure:"level"`
+	RPCLevel       string   `mapstructure:"rpc_level"`
+	ConsensusLevel string   `mapstructure:"consensus_level"`
+	DBLevel        string   `mapstructure:"db_level"`
+	Format         string   `mapstructure:"format"`
+	TimeEncoding   string   `mapstructure:"time_format"`
+	OutputPaths    []string `mapstructure:"output_paths"`
 }
 
 type AppConfig struct {
@@ -572,7 +575,7 @@ func DefaultConfig() *KwildConfig {
 			Level:        "info",
 			Format:       log.FormatJSON,
 			TimeEncoding: log.TimeEncodingEpochFloat,
-			OutputPaths:  []string{"stdout"},
+			OutputPaths:  []string{"stdout", "kwild.log"},
 		},
 
 		ChainCfg: &ChainConfig{

cmd/kwild/config/config_test.go

@@ -16,6 +16,10 @@ func Test_Config_Toml(t *testing.T) {
 	err = cfg.Merge(tomlCfg)
 	assert.NoError(t, err)
 
+	assert.Equal(t, "debug", cfg.Logging.Level)
+	assert.Equal(t, "info", cfg.Logging.RPCLevel)
+	assert.Equal(t, "warn", cfg.Logging.ConsensusLevel)
+
 	assert.Equal(t, "192.168.1.1:8484", cfg.AppCfg.JSONRPCListenAddress)
 	assert.Equal(t, "localhost:8080", cfg.AppCfg.HTTPListenAddress)
 

cmd/kwild/config/default_config.toml

@@ -120,11 +120,21 @@ snapshot_dir = "snapshots"
 ###                    Logging Config Options                       ###
 #######################################################################
 [log]
+
 # Output level for logging, default is "info". Other options are "debug", "error", "warn", "trace"
-level = "info" 
+level = "info"
+
+# RPC systems' logging level. Must be higher than log.level.
+rpc_level = "info"
+
+# Consensus engine's logging level. Must be higher than log.level.
+consensus_level = "warn"
+
+# DB driver's logging level. Must be higher than log.level.
+db_level = "info"
 
 # Output paths for the logger, can be stdout or a file path
-output_paths = ["stdout"]
+output_paths = ["stdout","kwild.log"]
 
 # Output format: 'plain' or 'json'
 format = "plain"

cmd/kwild/config/flags.go

@@ -8,6 +8,9 @@ func AddConfigFlags(flagSet *pflag.FlagSet, cfg *KwildConfig) {
 
 	// logging
 	flagSet.StringVarP(&cfg.Logging.Level, "log.level", "l", cfg.Logging.Level, "kwild log level")
+	flagSet.StringVar(&cfg.Logging.RPCLevel, "log.rpc_level", cfg.Logging.RPCLevel, "user rpc server log level")
+	flagSet.StringVar(&cfg.Logging.ConsensusLevel, "log.consensus_level", cfg.Logging.ConsensusLevel, "consensus (cometbft) log level")
+	flagSet.StringVar(&cfg.Logging.DBLevel, "log.db_level", cfg.Logging.DBLevel, "database backend (postgres) log level")
 	flagSet.StringVar(&cfg.Logging.Format, "log.format", cfg.Logging.Format, "kwild log format")
 	flagSet.StringVar(&cfg.Logging.TimeEncoding, "log.time-format", cfg.Logging.TimeEncoding, "kwild time log format")
 	flagSet.StringSliceVar(&cfg.Logging.OutputPaths, "log.output-paths", cfg.Logging.OutputPaths, "kwild log output paths")

cmd/kwild/config/test_data/config.toml

@@ -117,7 +117,16 @@ snapshot_dir = "data/snapshots"
 #######################################################################
 [log]
 # Output level for logging, default is "info". Other options are "debug", "error", "warn", "trace"
-level = "info" 
+level = "debug"
+
+# RPC systems' logging level. Must be higher than log.level.
+rpc_level = "info"
+
+# Consensus engine's logging level. Must be higher than log.level.
+consensus_level = "warn"
+
+# DB driver's logging level. Must be higher than log.level.
+db_level = "info"
 
 # Output paths for the logger, can be stdout or a file path
 output_paths = ["stdout"]

cmd/kwild/server/build.go

@@ -210,10 +210,13 @@ func buildServer(d *coreDependencies, closers *closeFuncs) *Server {
 	listeners := buildListenerManager(d, ev, cometBftNode, txApp)
 
 	// user service and server
+	rpcSvcLogger := increaseLogLevel("user-json-svc", &d.log, d.cfg.Logging.RPCLevel)
+	rpcServerLogger := increaseLogLevel("user-jsonrpc-server", &d.log, d.cfg.Logging.RPCLevel)
+
 	jsonRPCTxSvc := usersvc.NewService(db, e, wrappedCmtClient, txApp,
-		*d.log.Named("user-json-svc"), usersvc.WithReadTxTimeout(time.Duration(d.cfg.AppCfg.ReadTxTimeout)))
+		*rpcSvcLogger, usersvc.WithReadTxTimeout(time.Duration(d.cfg.AppCfg.ReadTxTimeout)))
 	jsonRPCServer, err := rpcserver.NewServer(d.cfg.AppCfg.JSONRPCListenAddress,
-		*d.log.Named("user-jsonrpc-server"), rpcserver.WithTimeout(time.Duration(d.cfg.AppCfg.RPCTimeout)),
+		*rpcServerLogger, rpcserver.WithTimeout(time.Duration(d.cfg.AppCfg.RPCTimeout)),
 		rpcserver.WithCORS())
 	if err != nil {
 		failBuild(err, "unable to create json-rpc server")
@@ -848,7 +851,7 @@ func buildCometNode(d *coreDependencies, closer *closeFuncs, abciApp abciTypes.A
 	// I'm simply using this because we know it fsyncs the data to disk
 	db, err := badger.NewBadgerDB(d.ctx, filepath.Join(d.cfg.RootDir, signingDirName), &badger.Options{
 		GuaranteeFSync: true,
-		Logger:         *d.log.Named("private-validator-signature-store"),
+		Logger:         *increaseLogLevel("private-validator-signature-store", &d.log, log.WarnLevel.String()), // badger is too noisy for an internal component
 	})
 	if err != nil {
 		failBuild(err, "failed to open comet node KV store")
@@ -874,8 +877,9 @@ func buildCometNode(d *coreDependencies, closer *closeFuncs, abciApp abciTypes.A
 		}
 	}
 
+	nodeLogger := increaseLogLevel("cometbft", &d.log, d.cfg.Logging.ConsensusLevel)
 	node, err := cometbft.NewCometBftNode(d.ctx, abciApp, nodeCfg, genDoc, d.privKey,
-		readWriter, &d.log)
+		readWriter, nodeLogger)
 	if err != nil {
 		failBuild(err, "failed to build comet node")
 	}

cmd/kwild/server/server.go

@@ -95,7 +95,8 @@ func New(ctx context.Context, cfg *config.KwildConfig, genesisCfg *config.Genesi
 		return nil, err
 	}
 
-	pg.UseLogger(*logger.Named("pg"))
+	dbLogger := increaseLogLevel("pg", &logger, cfg.Logging.DBLevel)
+	pg.UseLogger(*dbLogger)
 
 	host, port, user, pass := cfg.AppCfg.DBHost, cfg.AppCfg.DBPort, cfg.AppCfg.DBUser, cfg.AppCfg.DBPass
 

cmd/kwild/server/utils.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"strings"
 
+	"github.com/kwilteam/kwil-db/core/log"
 	types "github.com/kwilteam/kwil-db/core/types/admin"
 	"github.com/kwilteam/kwil-db/extensions/precompiles"
 	"github.com/kwilteam/kwil-db/internal/abci"
@@ -20,6 +21,27 @@ import (
 	cmttypes "github.com/cometbft/cometbft/types"
 )
 
+func increaseLogLevel(name string, logger *log.Logger, level string) *log.Logger {
+	logger = logger.Named(name)
+	if level == "" {
+		return logger
+	}
+
+	lvl, err := log.ParseLevel(level)
+	if err != nil {
+		logger.Warnf("invalid log level %q for logger %q: %v", level, name, err)
+		return logger
+	}
+
+	if parentLevel := logger.Level(); lvl < parentLevel {
+		logger.Warnf("cannot increase logger level for %q to %v from %v", name, level, parentLevel)
+	} else { // this would be a no-op
+		logger = logger.IncreasedLevel(lvl)
+	}
+
+	return logger
+}
+
 // getExtensions returns both the local and remote extensions. Remote extensions are identified by
 // connecting to the specified extension URLs.
 func getExtensions(ctx context.Context, urls []string) (map[string]precompiles.Initializer, error) {

core/log/logger.go

@@ -95,6 +95,12 @@ func (l *Logger) WithOptions(opts ...zap.Option) *Logger {
 	return &Logger{l.L.WithOptions(opts...)}
 }
 
+// IncreasedLevel creates a logger clone with a higher log level threshold,
+// which is ignored if it is lower than the parent logger's level.
+func (l *Logger) IncreasedLevel(lvl Level) *Logger {
+	return l.WithOptions(zap.IncreaseLevel(zap.NewAtomicLevelAt(lvl)))
+}
+
 func (l *Logger) Sync() error {
 	return l.L.Sync()
 }
@@ -201,6 +207,16 @@ const (
 	FatalLevel        = zap.FatalLevel
 )
 
+// ParseLevel parses a log level string, which is useful for reading level
+// settings from a config file or other text source.
+func ParseLevel(lvl string) (Level, error) {
+	l, err := zapcore.ParseLevel(lvl)
+	if err != nil {
+		return zapcore.InvalidLevel, err
+	}
+	return l, nil
+}
+
 func NewStdOut(level Level) Logger {
 	return New(Config{
 		Level:       level.String(),

internal/abci/cometbft/node.go

@@ -31,6 +31,7 @@ var demotedInfoMsgs = map[string]string{
 	"received proposal":                "",
 	"received complete proposal block": "",
 	"executed block":                   "",
+	"Starting localClient service":     "proxy",
 	"Timed out":                        "consensus", // only the one from consensus.(*timeoutTicker).timeoutRoutine, which seems to be normal
 }
 
@@ -164,7 +165,9 @@ WARNING: These files are overwritten on kwild startup.`
 }
 
 // NewCometBftNode creates a new CometBFT node.
-func NewCometBftNode(ctx context.Context, app abciTypes.Application, conf *cometConfig.Config, genDoc *types.GenesisDoc, privateKey cometEd25519.PrivKey, atomicStore privval.AtomicReadWriter, log *log.Logger) (*CometBftNode, error) {
+func NewCometBftNode(ctx context.Context, app abciTypes.Application, conf *cometConfig.Config,
+	genDoc *types.GenesisDoc, privateKey cometEd25519.PrivKey, atomicStore privval.AtomicReadWriter,
+	logger *log.Logger) (*CometBftNode, error) {
 	if err := writeCometBFTConfigs(conf, genDoc); err != nil {
 		return nil, fmt.Errorf("failed to write the effective cometbft config files: %w", err)
 	}
@@ -174,8 +177,6 @@ func NewCometBftNode(ctx context.Context, app abciTypes.Application, conf *comet
 		return nil, fmt.Errorf("invalid node config: %w", err)
 	}
 
-	logger := NewLogWrapper(log.Named("cometbft"))
-
 	privateValidator, err := privval.NewValidatorSigner(privateKey, atomicStore)
 	if err != nil {
 		return nil, fmt.Errorf("failed to create private validator: %v", err)
@@ -192,7 +193,7 @@ func NewCometBftNode(ctx context.Context, app abciTypes.Application, conf *comet
 		genesisDocProvider(genDoc),
 		cometConfig.DefaultDBProvider,
 		cometNodes.DefaultMetricsProvider(conf.Instrumentation),
-		logger,
+		NewLogWrapper(logger),
 	)
 	if err != nil {
 		if errors.Is(ctx.Err(), context.Canceled) {