From 3e1dcf2db6022a643241f81ae6018c8732c27fbf Mon Sep 17 00:00:00 2001 From: Mario Apra Date: Wed, 30 Oct 2024 11:55:06 +0000 Subject: [PATCH 1/2] Add debug-related files to .gitignore Ignored log and state files generated during Juno debugging in VS Code. Prevents clutter and accidental commits of temporary debug files. --- .gitignore | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/.gitignore b/.gitignore index cde234645..a6a45a764 100644 --- a/.gitignore +++ b/.gitignore @@ -9,4 +9,12 @@ config/ # Default path for Juno DB files. It will get created if you follow the # README and/or run `./build/juno` command. /juno/ -p2p-dbs \ No newline at end of file +p2p-dbs + +# Files created when debugging Juno. It will get created if you use the vscode debugger +*.log +*.sst +MANIFEST-* +OPTIONS-* +CURRENT +LOCK From 55eb191d431b1e1e536555cae68c7b49557545cf Mon Sep 17 00:00:00 2001 From: Mario Apra Date: Thu, 31 Oct 2024 16:45:56 +0000 Subject: [PATCH 2/2] Add runtime log level control via HTTP (Fix #1181) Introduce HTTP server to dynamically adjust log levels at runtime. Refactor log level handling to use a new LogLevel struct. Update tests and documentation to reflect these changes. Enhances logging flexibility and improves runtime configurability. --- cmd/juno/juno.go | 18 +++- cmd/juno/juno_test.go | 48 ++++++++-- db/pebble/db.go | 4 +- docs/docs/monitoring.md | 28 ++++++ node/http.go | 10 ++ node/node.go | 108 ++++++++++++---------- node/node_test.go | 8 +- utils/log.go | 101 ++++++++++++-------- utils/log_test.go | 200 ++++++++++++++++++++++++++++++++++++---- utils/network_test.go | 1 - vm/vm_test.go | 3 +- 11 files changed, 405 insertions(+), 124 deletions(-) diff --git a/cmd/juno/juno.go b/cmd/juno/juno.go index 1b973f8ef..6e0f98be5 100644 --- a/cmd/juno/juno.go +++ b/cmd/juno/juno.go @@ -84,6 +84,8 @@ const ( corsEnableF = "rpc-cors-enable" versionedConstantsFileF = "versioned-constants-file" pluginPathF = "plugin-path" + logHostF = "log-host" + logPortF = "log-port" defaultConfig = "" defaulHost = "localhost" @@ -123,6 +125,7 @@ const ( defaultCorsEnable = false defaultVersionedConstantsFile = "" defaultPluginPath = "" + defaultLogPort = 0 configFlagUsage = "The YAML configuration file." logLevelFlagUsage = "Options: trace, debug, info, warn, error." @@ -176,6 +179,8 @@ const ( corsEnableUsage = "Enable CORS on RPC endpoints" versionedConstantsFileUsage = "Use custom versioned constants from provided file" pluginPathUsage = "Path to the plugin .so file" + logHostUsage = "The interface on which the log level HTTP server will listen for requests." + logPortUsage = "The port on which the log level HTTP server will listen for requests." ) var Version string @@ -202,7 +207,13 @@ func main() { return err } - n, err := node.New(config, Version) + logLevel := utils.NewLogLevel(utils.INFO) + err = logLevel.Set(config.LogLevel) + if err != nil { + return err + } + + n, err := node.New(config, Version, logLevel) if err != nil { return err } @@ -307,13 +318,12 @@ func NewCmd(config *node.Config, run func(*cobra.Command, []string) error) *cobr // For testing purposes, these variables cannot be declared outside the function because Cobra // may mutate their values. - defaultLogLevel := utils.INFO defaultNetwork := utils.Mainnet defaultMaxVMs := 3 * runtime.GOMAXPROCS(0) defaultCNUnverifiableRange := []int{} // Uint64Slice is not supported in Flags() junoCmd.Flags().StringVar(&cfgFile, configF, defaultConfig, configFlagUsage) - junoCmd.Flags().Var(&defaultLogLevel, logLevelF, logLevelFlagUsage) + junoCmd.Flags().String(logLevelF, utils.INFO.String(), logLevelFlagUsage) junoCmd.Flags().Bool(httpF, defaultHTTP, httpUsage) junoCmd.Flags().String(httpHostF, defaulHost, httpHostUsage) junoCmd.Flags().Uint16(httpPortF, defaultHTTPPort, httpPortUsage) @@ -364,6 +374,8 @@ func NewCmd(config *node.Config, run func(*cobra.Command, []string) error) *cobr junoCmd.Flags().String(versionedConstantsFileF, defaultVersionedConstantsFile, versionedConstantsFileUsage) junoCmd.MarkFlagsMutuallyExclusive(p2pFeederNodeF, p2pPeersF) junoCmd.Flags().String(pluginPathF, defaultPluginPath, pluginPathUsage) + junoCmd.Flags().String(logHostF, defaulHost, logHostUsage) + junoCmd.Flags().Uint16(logPortF, defaultLogPort, logPortUsage) junoCmd.AddCommand(GenP2PKeyPair(), DBCmd(defaultDBPath)) diff --git a/cmd/juno/juno_test.go b/cmd/juno/juno_test.go index 7a3865407..7fc215209 100644 --- a/cmd/juno/juno_test.go +++ b/cmd/juno/juno_test.go @@ -30,7 +30,7 @@ func TestConfigPrecedence(t *testing.T) { // tested for sanity. These tests are not intended to perform semantics // checks on the config, those will be checked by the node implementation. defaultHost := "localhost" - defaultLogLevel := utils.INFO + defaultLogLevel := "info" defaultHTTP := false defaultHTTPPort := uint16(6060) defaultWS := false @@ -83,7 +83,7 @@ func TestConfigPrecedence(t *testing.T) { "--cn-core-contract-address", "0xc662c410C0ECf747543f5bA90660f6ABeBD9C8c4", }, expectedConfig: &node.Config{ - LogLevel: utils.DEBUG, + LogLevel: "debug", HTTP: defaultHTTP, HTTPHost: "0.0.0.0", HTTPPort: 4576, @@ -110,6 +110,8 @@ func TestConfigPrecedence(t *testing.T) { DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "custom network config file": { @@ -128,7 +130,7 @@ cn-core-contract-address: 0xc662c410C0ECf747543f5bA90660f6ABeBD9C8c4 cn-unverifiable-range: [0,10] `, expectedConfig: &node.Config{ - LogLevel: utils.DEBUG, + LogLevel: "debug", HTTP: defaultHTTP, HTTPHost: "0.0.0.0", HTTPPort: 4576, @@ -155,6 +157,8 @@ cn-unverifiable-range: [0,10] DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "default config with no flags": { @@ -187,6 +191,8 @@ cn-unverifiable-range: [0,10] DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "config file path is empty string": { @@ -219,6 +225,8 @@ cn-unverifiable-range: [0,10] DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "config file doesn't exist": { @@ -256,6 +264,8 @@ cn-unverifiable-range: [0,10] DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "config file with all settings but without any other flags": { @@ -268,7 +278,7 @@ network: sepolia pprof: true `, expectedConfig: &node.Config{ - LogLevel: utils.DEBUG, + LogLevel: "debug", HTTP: defaultHTTP, HTTPHost: "0.0.0.0", HTTPPort: 4576, @@ -295,6 +305,8 @@ pprof: true DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "config file with some settings but without any other flags": { @@ -304,7 +316,7 @@ http-host: 0.0.0.0 http-port: 4576 `, expectedConfig: &node.Config{ - LogLevel: utils.DEBUG, + LogLevel: "debug", HTTP: defaultHTTP, HTTPHost: "0.0.0.0", HTTPPort: 4576, @@ -331,6 +343,8 @@ http-port: 4576 DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "all flags without config file": { @@ -339,7 +353,7 @@ http-port: 4576 "--db-path", "/home/.juno", "--network", "sepolia-integration", "--pprof", "--db-cache-size", "1024", }, expectedConfig: &node.Config{ - LogLevel: utils.DEBUG, + LogLevel: "debug", HTTP: defaultHTTP, HTTPHost: "0.0.0.0", HTTPPort: 4576, @@ -366,6 +380,8 @@ http-port: 4576 RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, PendingPollInterval: defaultPendingPollInterval, + LogHost: defaultHost, + LogPort: 0, }, }, "some flags without config file": { @@ -374,7 +390,7 @@ http-port: 4576 "--network", "sepolia", }, expectedConfig: &node.Config{ - LogLevel: utils.DEBUG, + LogLevel: "debug", HTTP: defaultHTTP, HTTPHost: "0.0.0.0", HTTPPort: 4576, @@ -401,6 +417,8 @@ http-port: 4576 DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "all setting set in both config file and flags": { @@ -433,7 +451,7 @@ db-cache-size: 1024 "--db-cache-size", "9", }, expectedConfig: &node.Config{ - LogLevel: utils.ERROR, + LogLevel: "error", HTTP: true, HTTPHost: "127.0.0.1", HTTPPort: 4577, @@ -460,6 +478,8 @@ db-cache-size: 1024 DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "some setting set in both config file and flags": { @@ -471,7 +491,7 @@ network: sepolia `, inputArgs: []string{"--db-path", "/home/flag/.juno"}, expectedConfig: &node.Config{ - LogLevel: utils.WARN, + LogLevel: "warn", HTTP: defaultHTTP, HTTPHost: "0.0.0.0", HTTPPort: 4576, @@ -498,6 +518,8 @@ network: sepolia DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "some setting set in default, config file and flags": { @@ -532,6 +554,8 @@ network: sepolia DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "only set env variables": { @@ -564,6 +588,8 @@ network: sepolia DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "some setting set in both env variables and flags": { @@ -597,6 +623,8 @@ network: sepolia DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, "some setting set in both env variables and config file": { @@ -631,6 +659,8 @@ network: sepolia DBMaxHandles: defaultMaxHandles, RPCCallMaxSteps: defaultCallMaxSteps, GatewayTimeout: defaultGwTimeout, + LogHost: defaultHost, + LogPort: 0, }, }, } diff --git a/db/pebble/db.go b/db/pebble/db.go index 5974edf72..1a10d35bb 100644 --- a/db/pebble/db.go +++ b/db/pebble/db.go @@ -39,8 +39,8 @@ func New(path string) (db.DB, error) { func NewWithOptions(path string, cacheSizeMB uint, maxOpenFiles int, colouredLogger bool) (db.DB, error) { // Ensure that the specified cache size meets a minimum threshold. cacheSizeMB = max(cacheSizeMB, minCacheSizeMB) - - dbLog, err := utils.NewZapLogger(utils.ERROR, colouredLogger) + log := utils.NewLogLevel(utils.ERROR) + dbLog, err := utils.NewZapLogger(log, colouredLogger) if err != nil { return nil, fmt.Errorf("create DB logger: %w", err) } diff --git a/docs/docs/monitoring.md b/docs/docs/monitoring.md index f0abb49b3..e3b8a5717 100644 --- a/docs/docs/monitoring.md +++ b/docs/docs/monitoring.md @@ -85,3 +85,31 @@ To have Juno write logs to a file, use the command: ![Grafana dashboard](/img/grafana-1.png) ![Grafana dashboard](/img/grafana-2.png) + +## Change log level in runtime + +In case you want to change the log level in runtime without the need to restart the juno process, you can do it via HTTP calls. + +To enable this feature, use the following configuration options: + +- `log-host`: The interface to listen for requests. Defaults to `localhost`. +- `log-port`: The port to listen for requests. REQUIRED + +Examples: + +```console +# Start juno specifying the log port +juno --log-port=6789 --log-level=error ... + +# Get current level +curl -X GET 'localhost:6789/log/level' +error + +# Set level +curl -X PUT 'localhost:6789/log/level?level=trace' +Replaced log level with 'trace' successfully + +# Get new level +curl -X GET 'localhost:6789/log/level' +trace +``` diff --git a/node/http.go b/node/http.go index 4226564b0..bacd0db28 100644 --- a/node/http.go +++ b/node/http.go @@ -132,6 +132,16 @@ func makeMetrics(host string, port uint16) *httpService { promhttp.HandlerFor(prometheus.DefaultGatherer, promhttp.HandlerOpts{Registry: prometheus.DefaultRegisterer})) } +// Create a new service that updates the log level setting. +func makeLogService(host string, port uint16, logLevel *utils.LogLevel) *httpService { + mux := http.NewServeMux() + mux.HandleFunc("/log/level", func(w http.ResponseWriter, r *http.Request) { + utils.HTTPLogSettings(w, r, logLevel) + }) + var handler http.Handler = mux + return makeHTTPService(host, port, handler) +} + type grpcService struct { srv *grpc.Server host string diff --git a/node/node.go b/node/node.go index c048b5302..24abf4e28 100644 --- a/node/node.go +++ b/node/node.go @@ -46,28 +46,28 @@ const ( // Config is the top-level juno configuration. type Config struct { - LogLevel utils.LogLevel `mapstructure:"log-level"` - HTTP bool `mapstructure:"http"` - HTTPHost string `mapstructure:"http-host"` - HTTPPort uint16 `mapstructure:"http-port"` - RPCCorsEnable bool `mapstructure:"rpc-cors-enable"` - Websocket bool `mapstructure:"ws"` - WebsocketHost string `mapstructure:"ws-host"` - WebsocketPort uint16 `mapstructure:"ws-port"` - GRPC bool `mapstructure:"grpc"` - GRPCHost string `mapstructure:"grpc-host"` - GRPCPort uint16 `mapstructure:"grpc-port"` - DatabasePath string `mapstructure:"db-path"` - Network utils.Network `mapstructure:"network"` - EthNode string `mapstructure:"eth-node"` - DisableL1Verification bool `mapstructure:"disable-l1-verification"` - Pprof bool `mapstructure:"pprof"` - PprofHost string `mapstructure:"pprof-host"` - PprofPort uint16 `mapstructure:"pprof-port"` - Colour bool `mapstructure:"colour"` - PendingPollInterval time.Duration `mapstructure:"pending-poll-interval"` - RemoteDB string `mapstructure:"remote-db"` - VersionedConstantsFile string `mapstructure:"versioned-constants-file"` + LogLevel string `mapstructure:"log-level"` + HTTP bool `mapstructure:"http"` + HTTPHost string `mapstructure:"http-host"` + HTTPPort uint16 `mapstructure:"http-port"` + RPCCorsEnable bool `mapstructure:"rpc-cors-enable"` + Websocket bool `mapstructure:"ws"` + WebsocketHost string `mapstructure:"ws-host"` + WebsocketPort uint16 `mapstructure:"ws-port"` + GRPC bool `mapstructure:"grpc"` + GRPCHost string `mapstructure:"grpc-host"` + GRPCPort uint16 `mapstructure:"grpc-port"` + DatabasePath string `mapstructure:"db-path"` + Network utils.Network `mapstructure:"network"` + EthNode string `mapstructure:"eth-node"` + DisableL1Verification bool `mapstructure:"disable-l1-verification"` + Pprof bool `mapstructure:"pprof"` + PprofHost string `mapstructure:"pprof-host"` + PprofPort uint16 `mapstructure:"pprof-port"` + Colour bool `mapstructure:"colour"` + PendingPollInterval time.Duration `mapstructure:"pending-poll-interval"` + RemoteDB string `mapstructure:"remote-db"` + VersionedConstantsFile string `mapstructure:"versioned-constants-file"` Metrics bool `mapstructure:"metrics"` MetricsHost string `mapstructure:"metrics-host"` @@ -92,6 +92,9 @@ type Config struct { GatewayTimeout time.Duration `mapstructure:"gw-timeout"` PluginPath string `mapstructure:"plugin-path"` + + LogHost string `mapstructure:"log-host"` + LogPort uint16 `mapstructure:"log-port"` } type Node struct { @@ -99,17 +102,17 @@ type Node struct { db db.DB blockchain *blockchain.Blockchain - metricsService service.Service // Start the metrics service earlier than other services. - services []service.Service - log utils.Logger + earlyServices []service.Service // Services that needs to start before than other services and before migration. + services []service.Service + log utils.Logger version string } // New sets the config and logger to the StarknetNode. // Any errors while parsing the config on creating logger will be returned. -func New(cfg *Config, version string) (*Node, error) { //nolint:gocyclo,funlen - log, err := utils.NewZapLogger(cfg.LogLevel, cfg.Colour) +func New(cfg *Config, version string, logLevel *utils.LogLevel) (*Node, error) { //nolint:gocyclo,funlen + log, err := utils.NewZapLogger(logLevel, cfg.Colour) if err != nil { return nil, err } @@ -128,6 +131,7 @@ func New(cfg *Config, version string) (*Node, error) { //nolint:gocyclo,funlen ua := fmt.Sprintf("Juno/%s Starknet Client", version) services := make([]service.Service, 0) + earlyServices := make([]service.Service, 0) chain := blockchain.New(database, &cfg.Network) @@ -233,7 +237,10 @@ func New(cfg *Config, version string) (*Node, error) { //nolint:gocyclo,funlen services = append(services, makeRPCOverWebsocket(cfg.WebsocketHost, cfg.WebsocketPort, rpcServers, log, cfg.Metrics, cfg.RPCCorsEnable)) } - var metricsService service.Service + if cfg.LogPort != 0 { + log.Infow("Log level can be changed via HTTP PUT request to " + cfg.LogHost + ":" + fmt.Sprintf("%d", cfg.LogPort) + "/log/level") + earlyServices = append(earlyServices, makeLogService(cfg.LogHost, cfg.LogPort, logLevel)) + } if cfg.Metrics { makeJeMallocMetrics() makeVMThrottlerMetrics(throttledVM) @@ -246,7 +253,7 @@ func New(cfg *Config, version string) (*Node, error) { //nolint:gocyclo,funlen jsonrpcServerLegacy.WithListener(legacyRPCMetrics) client.WithListener(makeFeederMetrics()) gatewayClient.WithListener(makeGatewayMetrics()) - metricsService = makeMetrics(cfg.MetricsHost, cfg.MetricsPort) + earlyServices = append(earlyServices, makeMetrics(cfg.MetricsHost, cfg.MetricsPort)) if synchronizer != nil { synchronizer.WithListener(makeSyncMetrics(synchronizer, chain)) @@ -264,13 +271,13 @@ func New(cfg *Config, version string) (*Node, error) { //nolint:gocyclo,funlen } n := &Node{ - cfg: cfg, - log: log, - version: version, - db: database, - blockchain: chain, - services: services, - metricsService: metricsService, + cfg: cfg, + log: log, + version: version, + db: database, + blockchain: chain, + services: services, + earlyServices: earlyServices, } if !n.cfg.DisableL1Verification { @@ -351,13 +358,8 @@ func (n *Node) Run(ctx context.Context) { ctx, cancel := context.WithCancel(ctx) defer cancel() - if n.metricsService != nil { - wg.Go(func() { - defer cancel() - if err := n.metricsService.Run(ctx); err != nil { - n.log.Errorw("Metrics error", "err", err) - } - }) + for _, s := range n.earlyServices { + n.StartService(wg, ctx, cancel, s) } if err := migration.MigrateIfNeeded(ctx, n.db, &n.cfg.Network, n.log); err != nil { @@ -370,20 +372,24 @@ func (n *Node) Run(ctx context.Context) { } for _, s := range n.services { - wg.Go(func() { - // Immediately acknowledge panicing services by shutting down the node - // Without the deffered cancel(), we would have to wait for user to hit Ctrl+C - defer cancel() - if err := s.Run(ctx); err != nil { - n.log.Errorw("Service error", "name", reflect.TypeOf(s), "err", err) - } - }) + n.StartService(wg, ctx, cancel, s) } <-ctx.Done() n.log.Infow("Shutting down Juno...") } +func (n *Node) StartService(wg *conc.WaitGroup, ctx context.Context, cancel context.CancelFunc, s service.Service) { + wg.Go(func() { + // Immediately acknowledge panicing services by shutting down the node + // Without the deffered cancel(), we would have to wait for user to hit Ctrl+C + defer cancel() + if err := s.Run(ctx); err != nil { + n.log.Errorw("Service error", "name", reflect.TypeOf(s), "err", err) + } + }) +} + func (n *Node) Config() Config { return *n.cfg } diff --git a/node/node_test.go b/node/node_test.go index 1879bbb90..447ef6cc1 100644 --- a/node/node_test.go +++ b/node/node_test.go @@ -18,7 +18,7 @@ import ( // Create a new node with all services enabled. func TestNewNode(t *testing.T) { config := &node.Config{ - LogLevel: utils.INFO, + LogLevel: "info", HTTP: true, HTTPPort: 0, Websocket: true, @@ -40,7 +40,8 @@ func TestNewNode(t *testing.T) { P2PPeers: "", } - n, err := node.New(config, "v0.3") + logLevel := utils.NewLogLevel(utils.INFO) + n, err := node.New(config, "v0.3", logLevel) require.NoError(t, err) ctx, cancel := context.WithCancel(context.Background()) @@ -77,11 +78,12 @@ func TestNetworkVerificationOnNonEmptyDB(t *testing.T) { cancel() require.NoError(t, database.Close()) + logLevel := utils.NewLogLevel(utils.INFO) _, err = node.New(&node.Config{ DatabasePath: dbPath, Network: test.network, DisableL1Verification: true, - }, "v0.1") + }, "v0.1", logLevel) if test.errString == "" { require.NoError(t, err) } else { diff --git a/utils/log.go b/utils/log.go index 3d88ef3cb..0d3e497e9 100644 --- a/utils/log.go +++ b/utils/log.go @@ -3,6 +3,8 @@ package utils import ( "encoding" "fmt" + "html" + "net/http" "strings" "time" @@ -17,7 +19,17 @@ var ErrUnknownLogLevel = fmt.Errorf( TRACE, DEBUG, INFO, WARN, ERROR, ) -type LogLevel int +type LogLevel struct { + atomicLevel zap.AtomicLevel +} + +func (l LogLevel) GetAtomicLevel() zap.AtomicLevel { + return l.atomicLevel +} + +func NewLogLevel(level zapcore.Level) *LogLevel { + return &LogLevel{atomicLevel: zap.NewAtomicLevelAt(level)} +} // The following are necessary for Cobra and Viper, respectively, to unmarshal log level // CLI/config parameters properly. @@ -27,15 +39,15 @@ var ( ) const ( - DEBUG LogLevel = iota + TRACE zapcore.Level = iota - 2 + DEBUG INFO WARN ERROR - TRACE ) func (l LogLevel) String() string { - switch l { + switch l.Level() { case DEBUG: return "debug" case INFO: @@ -52,22 +64,26 @@ func (l LogLevel) String() string { } } +func (l LogLevel) Level() zapcore.Level { + return l.atomicLevel.Level() +} + func (l LogLevel) MarshalYAML() (interface{}, error) { return l.String(), nil } func (l *LogLevel) Set(s string) error { - switch s { - case "DEBUG", "debug": - *l = DEBUG - case "INFO", "info": - *l = INFO - case "WARN", "warn": - *l = WARN - case "ERROR", "error": - *l = ERROR - case "TRACE", "trace": - *l = TRACE + switch strings.ToUpper(s) { + case "DEBUG": + l.atomicLevel.SetLevel(DEBUG) + case "INFO": + l.atomicLevel.SetLevel(INFO) + case "WARN": + l.atomicLevel.SetLevel(WARN) + case "ERROR": + l.atomicLevel.SetLevel(ERROR) + case "TRACE": + l.atomicLevel.SetLevel(TRACE) default: return ErrUnknownLogLevel } @@ -103,10 +119,8 @@ type ZapLogger struct { *zap.SugaredLogger } -const traceLevel = zapcore.Level(-2) - func (l *ZapLogger) IsTraceEnabled() bool { - return l.Desugar().Core().Enabled(traceLevel) + return l.Desugar().Core().Enabled(TRACE) } func (l *ZapLogger) Tracew(msg string, keysAndValues ...interface{}) { @@ -117,7 +131,7 @@ func (l *ZapLogger) Tracew(msg string, keysAndValues ...interface{}) { // also check this issue https://github.com/uber-go/zap/issues/930 for updates // AddCallerSkip(1) is necessary to skip the caller of this function - l.WithOptions(zap.AddCallerSkip(1)).Logw(traceLevel, msg, keysAndValues...) + l.WithOptions(zap.AddCallerSkip(1)).Logw(TRACE, msg, keysAndValues...) } } @@ -127,7 +141,7 @@ func NewNopZapLogger() *ZapLogger { return &ZapLogger{zap.NewNop().Sugar()} } -func NewZapLogger(logLevel LogLevel, colour bool) (*ZapLogger, error) { +func NewZapLogger(logLevel *LogLevel, colour bool) (*ZapLogger, error) { config := zap.NewProductionConfig() config.Sampling = nil config.Encoding = "console" @@ -139,18 +153,7 @@ func NewZapLogger(logLevel LogLevel, colour bool) (*ZapLogger, error) { enc.AppendString(t.Local().Format("15:04:05.000 02/01/2006 -07:00")) } - var level zapcore.Level - var err error - levelStr := logLevel.String() - if logLevel == TRACE { - level = traceLevel - } else { - level, err = zapcore.ParseLevel(levelStr) - if err != nil { - return nil, err - } - } - config.Level.SetLevel(level) + config.Level = logLevel.atomicLevel log, err := config.Build() if err != nil { return nil, err @@ -179,9 +182,8 @@ func (c colour) Add(s string) string { // capitalColorLevelEncoder adds support for TRACE log level to the default CapitalColorLevelEncoder func capitalColorLevelEncoder(l zapcore.Level, enc zapcore.PrimitiveArrayEncoder) { - if l == traceLevel { - tracePrefix := strings.ToUpper(TRACE.String()) - enc.AppendString(cyan.Add(tracePrefix)) + if l == TRACE { + enc.AppendString(cyan.Add("TRACE")) } else { zapcore.CapitalColorLevelEncoder(l, enc) } @@ -189,10 +191,33 @@ func capitalColorLevelEncoder(l zapcore.Level, enc zapcore.PrimitiveArrayEncoder // capitalLevelEncoder adds support for TRACE log level to the default CapitalLevelEncoder func capitalLevelEncoder(l zapcore.Level, enc zapcore.PrimitiveArrayEncoder) { - if l == traceLevel { - tracePrefix := strings.ToUpper(TRACE.String()) - enc.AppendString(tracePrefix) + if l == TRACE { + enc.AppendString("TRACE") } else { zapcore.CapitalLevelEncoder(l, enc) } } + +// HTTPLogSettings is an HTTP handler that allows changing the log level of the logger. +// It can also be used to query what's the current log level. +func HTTPLogSettings(w http.ResponseWriter, r *http.Request, log *LogLevel) { + switch r.Method { + case http.MethodGet: + fmt.Fprint(w, log.String()+"\n") + case http.MethodPut: + levelStr := r.URL.Query().Get("level") + if levelStr == "" { + http.Error(w, "missing level query parameter", http.StatusBadRequest) + return + } + + err := log.Set(levelStr) + if err != nil { + http.Error(w, err.Error(), http.StatusBadRequest) + return + } + fmt.Fprint(w, "Replaced log level with '", html.EscapeString(levelStr), "' successfully\n") + default: + http.Error(w, "Method not allowed", http.StatusMethodNotAllowed) + } +} diff --git a/utils/log_test.go b/utils/log_test.go index 8a5954b87..71559451f 100644 --- a/utils/log_test.go +++ b/utils/log_test.go @@ -1,21 +1,30 @@ +//nolint:dupl package utils_test import ( + "bytes" + "context" "encoding/json" + "fmt" + "net/http" + "net/http/httptest" "strings" "testing" "github.com/NethermindEth/juno/utils" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "gopkg.in/yaml.v3" ) -var levelStrings = map[utils.LogLevel]string{ - utils.DEBUG: "debug", - utils.INFO: "info", - utils.WARN: "warn", - utils.ERROR: "error", - utils.TRACE: "trace", +var levelStrings = map[*utils.LogLevel]string{ + utils.NewLogLevel(utils.DEBUG): "debug", + utils.NewLogLevel(utils.INFO): "info", + utils.NewLogLevel(utils.WARN): "warn", + utils.NewLogLevel(utils.ERROR): "error", + utils.NewLogLevel(utils.TRACE): "trace", } func TestLogLevelString(t *testing.T) { @@ -30,20 +39,18 @@ func TestLogLevelString(t *testing.T) { // both implement the pflag.Value and encoding.TextUnmarshaller interfaces. // We can open a PR on github.com/thediveo/enumflag to add TextUnmarshaller // support. -// -//nolint:dupl func TestLogLevelSet(t *testing.T) { for level, str := range levelStrings { t.Run("level "+str, func(t *testing.T) { - l := new(utils.LogLevel) + l := utils.NewLogLevel(utils.TRACE) require.NoError(t, l.Set(str)) - assert.Equal(t, level, *l) + assert.Equal(t, *level, *l) }) uppercase := strings.ToUpper(str) t.Run("level "+uppercase, func(t *testing.T) { - l := new(utils.LogLevel) + l := utils.NewLogLevel(utils.TRACE) require.NoError(t, l.Set(uppercase)) - assert.Equal(t, level, *l) + assert.Equal(t, *level, *l) }) } @@ -56,15 +63,15 @@ func TestLogLevelSet(t *testing.T) { func TestLogLevelUnmarshalText(t *testing.T) { for level, str := range levelStrings { t.Run("level "+str, func(t *testing.T) { - l := new(utils.LogLevel) + l := utils.NewLogLevel(utils.TRACE) require.NoError(t, l.UnmarshalText([]byte(str))) - assert.Equal(t, level, *l) + assert.Equal(t, *level, *l) }) uppercase := strings.ToUpper(str) t.Run("level "+uppercase, func(t *testing.T) { - l := new(utils.LogLevel) + l := utils.NewLogLevel(utils.TRACE) require.NoError(t, l.UnmarshalText([]byte(uppercase))) - assert.Equal(t, level, *l) + assert.Equal(t, *level, *l) }) } @@ -107,3 +114,164 @@ func TestZapWithoutColour(t *testing.T) { }) } } + +func TestHTTPLogSettings(t *testing.T) { + logLevel := utils.NewLogLevel(utils.INFO) + ctx := context.Background() + + t.Run("GET current log level", func(t *testing.T) { + req, err := http.NewRequestWithContext(ctx, http.MethodGet, "/log/level", http.NoBody) + require.NoError(t, err) + + rr := httptest.NewRecorder() + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + utils.HTTPLogSettings(w, r, logLevel) + }) + + handler.ServeHTTP(rr, req) + + assert.Equal(t, http.StatusOK, rr.Code) + assert.Equal(t, "info\n", rr.Body.String()) + }) + + t.Run("PUT update log level", func(t *testing.T) { + req, err := http.NewRequestWithContext(ctx, http.MethodPut, "/log/level?level=debug", http.NoBody) + require.NoError(t, err) + + rr := httptest.NewRecorder() + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + utils.HTTPLogSettings(w, r, logLevel) + }) + + handler.ServeHTTP(rr, req) + + assert.Equal(t, http.StatusOK, rr.Code) + assert.Equal(t, "Replaced log level with 'debug' successfully\n", rr.Body.String()) + assert.Equal(t, utils.DEBUG, logLevel.Level()) + }) + + t.Run("PUT update log level with missing parameter", func(t *testing.T) { + req, err := http.NewRequestWithContext(ctx, http.MethodPut, "/log/level", http.NoBody) + require.NoError(t, err) + + rr := httptest.NewRecorder() + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + utils.HTTPLogSettings(w, r, logLevel) + }) + + handler.ServeHTTP(rr, req) + + assert.Equal(t, http.StatusBadRequest, rr.Code) + assert.Equal(t, "missing level query parameter\n", rr.Body.String()) + }) + + t.Run("PUT update log level with invalid level", func(t *testing.T) { + req, err := http.NewRequestWithContext(ctx, http.MethodPut, "/log/level?level=invalid", http.NoBody) + require.NoError(t, err) + + rr := httptest.NewRecorder() + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + utils.HTTPLogSettings(w, r, logLevel) + }) + + handler.ServeHTTP(rr, req) + + assert.Equal(t, http.StatusBadRequest, rr.Code) + assert.Equal(t, rr.Body.String(), fmt.Sprint(utils.ErrUnknownLogLevel)+"\n") + }) + + t.Run("Method not allowed", func(t *testing.T) { + req, err := http.NewRequestWithContext(ctx, http.MethodPost, "/log/level", http.NoBody) + require.NoError(t, err) + + rr := httptest.NewRecorder() + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + utils.HTTPLogSettings(w, r, logLevel) + }) + + handler.ServeHTTP(rr, req) + + assert.Equal(t, http.StatusMethodNotAllowed, rr.Code) + assert.Equal(t, "Method not allowed\n", rr.Body.String()) + }) +} + +func TestMarshalYAML(t *testing.T) { + tests := []struct { + name string + logLevel utils.LogLevel + expected string + }{ + {"InfoLevel", *utils.NewLogLevel(utils.INFO), "info"}, + {"DebugLevel", *utils.NewLogLevel(utils.DEBUG), "debug"}, + {"ErrorLevel", *utils.NewLogLevel(utils.ERROR), "error"}, + {"WarnLevel", *utils.NewLogLevel(utils.WARN), "warn"}, + {"TraceLevel", *utils.NewLogLevel(utils.TRACE), "trace"}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + data, err := yaml.Marshal(tt.logLevel) + assert.NoError(t, err) + assert.Contains(t, string(data), tt.expected) + }) + } +} + +func TestIsTraceEnabled(t *testing.T) { + t.Run("Trace enabled", func(t *testing.T) { + logLevel := utils.NewLogLevel(utils.TRACE) + logger, err := utils.NewZapLogger(logLevel, false) + require.NoError(t, err) + assert.True(t, logger.IsTraceEnabled()) + }) + + t.Run("Trace disabled", func(t *testing.T) { + logLevel := utils.NewLogLevel(utils.INFO) + logger, err := utils.NewZapLogger(logLevel, false) + require.NoError(t, err) + assert.False(t, logger.IsTraceEnabled()) + }) +} + +func TestTracew(t *testing.T) { + var buf bytes.Buffer + + t.Run("Tracew with trace level enabled", func(t *testing.T) { + logLevel := utils.NewLogLevel(utils.TRACE) + + core := zapcore.NewCore( + zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig()), + zapcore.AddSync(&buf), + logLevel.Level(), + ) + + logger := zap.New(core).Sugar() + zapLogger := &utils.ZapLogger{SugaredLogger: logger} + expectedMessage := "trace message" + zapLogger.Tracew(expectedMessage) + + logOutput := buf.String() + assert.Contains(t, logOutput, expectedMessage) + }) + + t.Run("Tracew with trace level disabled", func(t *testing.T) { + buf.Reset() + + logLevel := utils.NewLogLevel(utils.INFO) + + core := zapcore.NewCore( + zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig()), + zapcore.AddSync(&buf), + logLevel.Level(), + ) + + logger := zap.New(core).Sugar() + zapLogger := &utils.ZapLogger{SugaredLogger: logger} + expectedMessage := "trace message" + zapLogger.Tracew(expectedMessage) + + logOutput := buf.String() + assert.NotContains(t, logOutput, expectedMessage) + }) +} diff --git a/utils/network_test.go b/utils/network_test.go index 778f66545..33d5b7ec5 100644 --- a/utils/network_test.go +++ b/utils/network_test.go @@ -83,7 +83,6 @@ func TestNetwork(t *testing.T) { }) } -//nolint:dupl // see comment in utils/log_test.go func TestNetworkSet(t *testing.T) { for network, str := range networkStrings { t.Run("network "+str, func(t *testing.T) { diff --git a/vm/vm_test.go b/vm/vm_test.go index 00832b606..b56b26b78 100644 --- a/vm/vm_test.go +++ b/vm/vm_test.go @@ -110,7 +110,8 @@ func TestV1Call(t *testing.T) { *classHash: simpleClass, })) - log, err := utils.NewZapLogger(utils.ERROR, false) + logLevel := utils.NewLogLevel(utils.ERROR) + log, err := utils.NewZapLogger(logLevel, false) require.NoError(t, err) // test_storage_read