diff --git a/api/geth_backend.go b/api/geth_backend.go index 81dbc16c5..09aae5537 100644 --- a/api/geth_backend.go +++ b/api/geth_backend.go @@ -498,7 +498,7 @@ func (b *GethStatusBackend) setupLogSettings() error { MaxBackups: b.config.LogMaxBackups, CompressRotated: b.config.LogCompressRotated, } - if err := logutils.OverrideRootLogWithConfig(logSettings, false); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logSettings); err != nil { return err } return nil diff --git a/cmd/ping-community/main.go b/cmd/ping-community/main.go index c2754aa62..0ced6b2aa 100644 --- a/cmd/ping-community/main.go +++ b/cmd/ping-community/main.go @@ -73,8 +73,11 @@ func init() { // nolint:gocyclo func main() { - colors := terminal.IsTerminal(int(os.Stdin.Fd())) - if err := logutils.OverrideRootLog(true, "ERROR", logutils.FileOptions{}, colors); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logutils.LogSettings{ + Enabled: true, + Level: "ERROR", + Colorized: terminal.IsTerminal(int(os.Stdin.Fd())), + }); err != nil { stdlog.Fatalf("Error initializing logger: %v", err) } @@ -241,9 +244,9 @@ func setupLogging(config *params.NodeConfig) { MaxSize: config.LogMaxSize, MaxBackups: config.LogMaxBackups, CompressRotated: config.LogCompressRotated, + Colorized: !(*logWithoutColors) && terminal.IsTerminal(int(os.Stdin.Fd())), } - colors := !(*logWithoutColors) && terminal.IsTerminal(int(os.Stdin.Fd())) - if err := logutils.OverrideRootLogWithConfig(logSettings, colors); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logSettings); err != nil { stdlog.Fatalf("Error initializing logger: %v", err) } } diff --git a/cmd/populate-db/main.go b/cmd/populate-db/main.go index 1d55a8db3..593fccadf 100644 --- a/cmd/populate-db/main.go +++ b/cmd/populate-db/main.go @@ -82,8 +82,11 @@ func init() { // nolint:gocyclo func main() { - colors := terminal.IsTerminal(int(os.Stdin.Fd())) - if err := logutils.OverrideRootLog(true, "ERROR", logutils.FileOptions{}, colors); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logutils.LogSettings{ + Enabled: true, + Level: "ERROR", + Colorized: terminal.IsTerminal(int(os.Stdin.Fd())), + }); err != nil { stdlog.Fatalf("Error initializing logger: %v", err) } @@ -285,9 +288,9 @@ func setupLogging(config *params.NodeConfig) { MaxSize: config.LogMaxSize, MaxBackups: config.LogMaxBackups, CompressRotated: config.LogCompressRotated, + Colorized: !(*logWithoutColors) && terminal.IsTerminal(int(os.Stdin.Fd())), } - colors := !(*logWithoutColors) && terminal.IsTerminal(int(os.Stdin.Fd())) - if err := logutils.OverrideRootLogWithConfig(logSettings, colors); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logSettings); err != nil { stdlog.Fatalf("Error initializing logger: %v", err) } } diff --git a/cmd/status-backend/main.go b/cmd/status-backend/main.go index 763b15c8f..a1d4e56d3 100644 --- a/cmd/status-backend/main.go +++ b/cmd/status-backend/main.go @@ -24,9 +24,9 @@ func init() { Enabled: true, MobileSystem: false, Level: "INFO", + Colorized: terminal.IsTerminal(int(os.Stdin.Fd())), } - colors := terminal.IsTerminal(int(os.Stdin.Fd())) - if err := logutils.OverrideRootLogWithConfig(logSettings, colors); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logSettings); err != nil { stdlog.Fatalf("failed to initialize log: %v", err) } } diff --git a/cmd/status-cli/util.go b/cmd/status-cli/util.go index 04a6ac514..7b38447e1 100644 --- a/cmd/status-cli/util.go +++ b/cmd/status-cli/util.go @@ -32,7 +32,7 @@ func setupLogger(file string) *zap.Logger { MaxBackups: 3, CompressRotated: true, } - if err := logutils.OverrideRootLogWithConfig(logSettings, false); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logSettings); err != nil { zap.S().Fatalf("Error initializing logger: %v", err) } return logutils.ZapLogger() diff --git a/cmd/statusd/main.go b/cmd/statusd/main.go index 8c02792b8..aa1c61692 100644 --- a/cmd/statusd/main.go +++ b/cmd/statusd/main.go @@ -100,8 +100,11 @@ func init() { // nolint:gocyclo func main() { - colors := terminal.IsTerminal(int(os.Stdin.Fd())) - if err := logutils.OverrideRootLog(true, "ERROR", logutils.FileOptions{}, colors); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logutils.LogSettings{ + Enabled: true, + Level: "ERROR", + Colorized: terminal.IsTerminal(int(os.Stdin.Fd())), + }); err != nil { stdlog.Fatalf("Error initializing logger: %v", err) } @@ -399,9 +402,9 @@ func setupLogging(config *params.NodeConfig) { MaxSize: config.LogMaxSize, MaxBackups: config.LogMaxBackups, CompressRotated: config.LogCompressRotated, + Colorized: !(*logWithoutColors) && terminal.IsTerminal(int(os.Stdin.Fd())), } - colors := !(*logWithoutColors) && terminal.IsTerminal(int(os.Stdin.Fd())) - if err := logutils.OverrideRootLogWithConfig(logSettings, colors); err != nil { + if err := logutils.OverrideRootLoggerWithConfig(logSettings); err != nil { stdlog.Fatalf("Error initializing logger: %v", err) } } diff --git a/logutils/core.go b/logutils/core.go index 8f1aa1512..b6e153cbf 100644 --- a/logutils/core.go +++ b/logutils/core.go @@ -53,6 +53,14 @@ func (core *Core) Enabled(lvl zapcore.Level) bool { return core.level.Enabled(lvl) } +func (core *Core) Level() zapcore.Level { + return core.level.Level() +} + +func (core *Core) SetLevel(lvl zapcore.Level) { + core.level.SetLevel(lvl) +} + func (core *Core) With(fields []zapcore.Field) zapcore.Core { clonedEncoder := encoderWrapper{Encoder: core.getEncoder().Clone()} for i := range fields { diff --git a/logutils/logger.go b/logutils/logger.go index 9ed84e058..f81b2880b 100644 --- a/logutils/logger.go +++ b/logutils/logger.go @@ -1,11 +1,15 @@ package logutils import ( + "io" "sync" + "time" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/ethereum/go-ethereum/log" + "github.com/status-im/status-go/protocol/zaputil" ) var ( @@ -13,15 +17,35 @@ var ( _initZapLogger sync.Once ) -// ZapLogger creates a custom zap.Logger which will forward logs -// to status-go logger. func ZapLogger() *zap.Logger { _initZapLogger.Do(func() { - var err error - _zapLogger, err = NewZapLoggerWithAdapter(log.Root()) - if err != nil { - panic(err) - } + _zapLogger = defaultLogger() + + // forward geth logs to zap logger + _gethLogger := _zapLogger.Named("geth") + log.Root().SetHandler(gethAdapter(_gethLogger)) }) return _zapLogger } + +func defaultLogger() *zap.Logger { + core := NewCore( + defaultEncoder(), + zapcore.AddSync(io.Discard), + zap.NewAtomicLevelAt(zap.InfoLevel), + ) + return zap.New(core, zap.AddCaller()) +} + +func defaultEncoder() zapcore.Encoder { + encoderConfig := zap.NewDevelopmentEncoderConfig() + encoderConfig.EncodeTime = utcTimeEncoder(encoderConfig.EncodeTime) + + return zaputil.NewConsoleHexEncoder(encoderConfig) +} + +func utcTimeEncoder(encoder zapcore.TimeEncoder) zapcore.TimeEncoder { + return func(t time.Time, enc zapcore.PrimitiveArrayEncoder) { + encoder(t.UTC(), enc) + } +} diff --git a/logutils/logger_test.go b/logutils/logger_test.go index a76256c40..999304507 100644 --- a/logutils/logger_test.go +++ b/logutils/logger_test.go @@ -5,14 +5,16 @@ import ( "testing" "github.com/stretchr/testify/require" - - "github.com/ethereum/go-ethereum/log" + "go.uber.org/zap/zapcore" ) func TestPrintOrigins(t *testing.T) { - buf := bytes.NewBuffer(nil) - handler := log.StreamHandler(buf, log.TerminalFormat(false)) - require.NoError(t, enableRootLog("debug", handler)) - log.Debug("hello") - require.Contains(t, buf.String(), "logutils/logger_test.go:16") + buffer := bytes.NewBuffer(nil) + + logger := defaultLogger() + logger.Core().(*Core).UpdateSyncer(zapcore.AddSync(buffer)) + + logger.Info("hello") + + require.Contains(t, buffer.String(), "logutils/logger_test.go:17") } diff --git a/logutils/logrotation.go b/logutils/logrotation.go index 27934b023..47eefccef 100644 --- a/logutils/logrotation.go +++ b/logutils/logrotation.go @@ -3,8 +3,6 @@ package logutils import ( "go.uber.org/zap/zapcore" "gopkg.in/natefinch/lumberjack.v2" - - "github.com/ethereum/go-ethereum/log" ) // FileOptions are all options supported by internal rotation module. @@ -19,17 +17,6 @@ type FileOptions struct { Compress bool } -// FileHandlerWithRotation instantiates log.Handler with a configured rotation -func FileHandlerWithRotation(opts FileOptions, format log.Format) log.Handler { - logger := &lumberjack.Logger{ - Filename: opts.Filename, - MaxSize: opts.MaxSize, - MaxBackups: opts.MaxBackups, - Compress: opts.Compress, - } - return log.StreamHandler(logger, format) -} - // ZapSyncerWithRotation creates a zapcore.WriteSyncer with a configured rotation func ZapSyncerWithRotation(opts FileOptions) zapcore.WriteSyncer { return zapcore.AddSync(&lumberjack.Logger{ diff --git a/logutils/override.go b/logutils/override.go index 44498b2f4..65e68c16f 100644 --- a/logutils/override.go +++ b/logutils/override.go @@ -1,12 +1,12 @@ package logutils import ( + "io" "os" - "strings" logging "github.com/ipfs/go-log/v2" - "github.com/ethereum/go-ethereum/log" + "go.uber.org/zap/zapcore" ) type LogSettings struct { @@ -17,84 +17,58 @@ type LogSettings struct { MaxSize int `json:"MaxSize"` MaxBackups int `json:"MaxBackups"` CompressRotated bool `json:"CompressRotated"` + Colorized bool `json:"Colorized"` // FIXME: doesn't take effect } -// OverrideWithStdLogger overwrites ethereum's root logger with a logger from golang std lib. -func OverrideWithStdLogger(logLevel string) error { - return enableRootLog(logLevel, NewStdHandler(log.TerminalFormat(false))) +func OverrideRootLoggerWithConfig(settings LogSettings) error { + return overrideCoreWithConfig(ZapLogger().Core().(*Core), settings) } -// OverrideRootLogWithConfig derives all configuration from params.NodeConfig and configures logger using it. -func OverrideRootLogWithConfig(settings LogSettings, colors bool) error { +func overrideCoreWithConfig(core *Core, settings LogSettings) error { if !settings.Enabled { + core.UpdateSyncer(zapcore.AddSync(io.Discard)) return nil } + + if settings.Level == "" { + settings.Level = "info" + } + level, err := lvlFromString(settings.Level) + if err != nil { + return err + } + core.SetLevel(level) + if settings.MobileSystem { - return OverrideWithStdLogger(settings.Level) - } - return OverrideRootLog(settings.Enabled, settings.Level, FileOptions{ - Filename: settings.File, - MaxSize: settings.MaxSize, - MaxBackups: settings.MaxBackups, - Compress: settings.CompressRotated, - }, colors) - -} - -// OverrideRootLog overrides root logger with file handler, if defined, -// and log level (defaults to INFO). -func OverrideRootLog(enabled bool, levelStr string, fileOpts FileOptions, terminal bool) error { - if !enabled { - disableRootLog() + core.UpdateSyncer(zapcore.Lock(os.Stdout)) return nil } - if os.Getenv("CI") == "true" { - terminal = false - } - var ( - handler log.Handler - ) - if fileOpts.Filename != "" { - if fileOpts.MaxBackups == 0 { + + if settings.File != "" { + if settings.MaxBackups == 0 { // Setting MaxBackups to 0 causes all log files to be kept. Even setting MaxAge to > 0 doesn't fix it // Docs: https://pkg.go.dev/gopkg.in/natefinch/lumberjack.v2@v2.0.0#readme-cleaning-up-old-log-files - fileOpts.MaxBackups = 1 + settings.MaxBackups = 1 } - handler = FileHandlerWithRotation(fileOpts, log.TerminalFormat(terminal)) + core.UpdateSyncer(ZapSyncerWithRotation(FileOptions{ + Filename: settings.File, + MaxSize: settings.MaxSize, + MaxBackups: settings.MaxBackups, + Compress: settings.CompressRotated, + })) } else { - handler = log.StreamHandler(os.Stderr, log.TerminalFormat(terminal)) + core.UpdateSyncer(zapcore.Lock(os.Stderr)) } - return enableRootLog(levelStr, handler) -} - -func disableRootLog() { - log.Root().SetHandler(log.DiscardHandler()) -} - -func enableRootLog(levelStr string, handler log.Handler) error { - if levelStr == "" { - levelStr = "INFO" - } - - levelStr = strings.ToLower(levelStr) - - level, err := log.LvlFromString(levelStr) - if err != nil { - return err - } - - filteredHandler := log.LvlFilterHandler(level, handler) - log.Root().SetHandler(filteredHandler) - log.PrintOrigins(true) - + // FIXME: remove go-libp2p logging altogether // go-libp2p logger - lvl, err := logging.LevelFromString(levelStr) - if err != nil { - return err + { + lvl, err := logging.LevelFromString(settings.Level) + if err != nil { + return err + } + logging.SetAllLoggers(lvl) } - logging.SetAllLoggers(lvl) - return nil } diff --git a/logutils/override_test.go b/logutils/override_test.go new file mode 100644 index 000000000..f81c121a2 --- /dev/null +++ b/logutils/override_test.go @@ -0,0 +1,77 @@ +package logutils + +import ( + "io" + "testing" + + "github.com/stretchr/testify/require" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +func TestOverrideCoreWithConfig(t *testing.T) { + tests := []struct { + name string + settings LogSettings + expectError bool + }{ + { + name: "disabled logging", + settings: LogSettings{ + Enabled: false, + }, + expectError: false, + }, + { + name: "invalid log level", + settings: LogSettings{ + Enabled: true, + Level: "invalid", + }, + expectError: true, + }, + { + name: "valid log level", + settings: LogSettings{ + Enabled: true, + Level: "info", + }, + expectError: false, + }, + { + name: "mobile system logging", + settings: LogSettings{ + Enabled: true, + MobileSystem: true, + }, + expectError: false, + }, + { + name: "file logging with rotation", + settings: LogSettings{ + Enabled: true, + File: "test.log", + MaxSize: 10, + MaxBackups: 0, + CompressRotated: true, + }, + expectError: false, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + core := NewCore( + defaultEncoder(), + zapcore.AddSync(io.Discard), + zap.NewAtomicLevelAt(zap.InfoLevel), + ) + err := overrideCoreWithConfig(core, tt.settings) + if tt.expectError { + require.Error(t, err) + } else { + require.NoError(t, err) + } + }) + } +} diff --git a/logutils/stdhandler.go b/logutils/stdhandler.go deleted file mode 100644 index 5f2c81eba..000000000 --- a/logutils/stdhandler.go +++ /dev/null @@ -1,17 +0,0 @@ -package logutils - -import ( - stdlog "log" - - "github.com/ethereum/go-ethereum/log" -) - -// NewStdHandler returns handler that uses logger from golang std lib. -func NewStdHandler(fmtr log.Format) log.Handler { - return log.FuncHandler(func(r *log.Record) error { - line := fmtr.Format(r) - // 8 is a number of frames that will be skipped when log is printed. - // this is needed to show the file (with line number) where call to a logger was made - return stdlog.Output(8, string(line)) - }) -} diff --git a/logutils/zap_adapter.go b/logutils/zap_adapter.go deleted file mode 100644 index 57f8a938c..000000000 --- a/logutils/zap_adapter.go +++ /dev/null @@ -1,147 +0,0 @@ -package logutils - -import ( - "fmt" - "math" - "time" - - "go.uber.org/zap" - "go.uber.org/zap/zapcore" - - "github.com/ethereum/go-ethereum/log" - - "github.com/status-im/status-go/protocol/zaputil" -) - -type gethLoggerCore struct { - zapcore.LevelEnabler - fields []zapcore.Field - logger log.Logger -} - -func (c gethLoggerCore) With(fields []zapcore.Field) zapcore.Core { - clone := c.clone() - clone.fields = append(clone.fields, fields...) - return clone -} - -func (c gethLoggerCore) Check(ent zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry { - if c.Enabled(ent.Level) { - return ce.AddCore(ent, c) - } - return ce -} -func (c gethLoggerCore) Write(ent zapcore.Entry, fields []zapcore.Field) error { - fields = append(c.fields[:], fields...) - - var args []interface{} - for _, f := range fields { - switch f.Type { - case zapcore.ArrayMarshalerType, - zapcore.ObjectMarshalerType, - zapcore.BinaryType, - zapcore.ByteStringType, - zapcore.Complex128Type, - zapcore.ReflectType, - zapcore.StringerType, - zapcore.ErrorType: - args = append(args, f.Key, f.Interface) - case zapcore.BoolType: - args = append(args, f.Key, f.Integer == 1) - case zapcore.DurationType: - args = append(args, f.Key, time.Duration(f.Integer)) - case zapcore.Float64Type: - args = append(args, f.Key, math.Float64frombits(uint64(f.Integer))) - case zapcore.Float32Type: - args = append(args, f.Key, math.Float32frombits(uint32(f.Integer))) - case zapcore.Int64Type, - zapcore.Int32Type, - zapcore.Int16Type, - zapcore.Int8Type, - zapcore.Uint64Type, - zapcore.Uint32Type, - zapcore.Uint16Type, - zapcore.Uint8Type: - args = append(args, f.Key, f.Integer) - case zapcore.UintptrType: - args = append(args, f.Key, uintptr(f.Integer)) - case zapcore.StringType: - args = append(args, f.Key, f.String) - case zapcore.TimeType: - if f.Interface != nil { - args = append(args, f.Key, time.Unix(0, f.Integer).In(f.Interface.(*time.Location))) - } else { - // Fall back to UTC if location is nil. - args = append(args, f.Key, time.Unix(0, f.Integer)) - } - case zapcore.NamespaceType: - args = append(args, "namespace", f.Key) - case zapcore.SkipType: - break - default: - panic(fmt.Sprintf("unknown field type: %v", f)) - } - } - - // set callDepth to 3 for `Output` to skip the calls to zap.Logger - // and get the correct caller in the log - callDepth := 3 - switch ent.Level { - case zapcore.DebugLevel: - c.logger.Output(ent.Message, log.LvlDebug, callDepth, args...) - case zapcore.InfoLevel: - c.logger.Output(ent.Message, log.LvlInfo, callDepth, args...) - case zapcore.WarnLevel: - c.logger.Output(ent.Message, log.LvlWarn, callDepth, args...) - case zapcore.ErrorLevel: - c.logger.Output(ent.Message, log.LvlError, callDepth, args...) - case zapcore.DPanicLevel, zapcore.PanicLevel, zapcore.FatalLevel: - c.logger.Output(ent.Message, log.LvlCrit, callDepth, args...) - } - - return nil -} - -func (gethLoggerCore) Sync() error { - return nil -} - -func (c *gethLoggerCore) clone() *gethLoggerCore { - return &gethLoggerCore{ - LevelEnabler: c.LevelEnabler, - fields: c.fields, - logger: c.logger, - } -} - -// NewZapAdapter returns a new zapcore.Core interface which forwards logs to log.Logger. -func NewZapAdapter(logger log.Logger, enab zapcore.LevelEnabler) zapcore.Core { - return &gethLoggerCore{ - LevelEnabler: enab, - logger: logger, - } -} - -// NewZapLoggerWithAdapter returns a logger forwarding all logs with level info and above. -func NewZapLoggerWithAdapter(logger log.Logger) (*zap.Logger, error) { - if err := zaputil.RegisterJSONHexEncoder(); err != nil { - panic(err) - } - - cfg := zap.Config{ - Level: zap.NewAtomicLevelAt(zapcore.DebugLevel), - Development: false, - Sampling: nil, - Encoding: "json-hex", - EncoderConfig: zap.NewProductionEncoderConfig(), - OutputPaths: []string{"stderr"}, - ErrorOutputPaths: []string{"stderr"}, - } - adapter := zap.WrapCore( - func(zapcore.Core) zapcore.Core { - return NewZapAdapter(logger, cfg.Level) - }, - ) - log.PrintOrigins(true) - return cfg.Build(adapter) -} diff --git a/logutils/zap_adapter_test.go b/logutils/zap_adapter_test.go deleted file mode 100644 index 6dc138bef..000000000 --- a/logutils/zap_adapter_test.go +++ /dev/null @@ -1,72 +0,0 @@ -package logutils - -import ( - "bytes" - "errors" - "testing" - - "github.com/stretchr/testify/require" - "go.uber.org/zap" - - "github.com/ethereum/go-ethereum/log" -) - -func TestNewZapAdapter(t *testing.T) { - buf := bytes.NewBuffer(nil) - logger := log.New() - handler := log.StreamHandler(buf, log.LogfmtFormat()) - logger.SetHandler(handler) - - cfg := zap.NewDevelopmentConfig() - adapter := NewZapAdapter(logger, cfg.Level) - - zapLogger := zap.New(adapter) - - buf.Reset() - zapLogger. - With(zap.Error(errors.New("some error"))). - Error("some message with error level") - require.Contains(t, buf.String(), `lvl=eror msg="some message with error level" error="some error`) - - buf.Reset() - zapLogger. - With(zap.Int("counter", 100)). - Info("some message with param", zap.String("another-field", "another-value")) - require.Contains(t, buf.String(), `lvl=info msg="some message with param" counter=100 another-field=another-value`) - - buf.Reset() - zapLogger. - With(zap.Namespace("some-namespace")). - With(zap.String("site", "SomeSite")). - Info("some message with param") - require.Contains(t, buf.String(), `lvl=info msg="some message with param" namespace=some-namespace site=SomeSite`) -} - -func TestNewZapLoggerWithAdapter(t *testing.T) { - buf := bytes.NewBuffer(nil) - logger := log.New() - handler := log.StreamHandler(buf, log.LogfmtFormat()) - logger.SetHandler(handler) - - zapLogger, err := NewZapLoggerWithAdapter(logger) - require.NoError(t, err) - - buf.Reset() - zapLogger. - With(zap.Error(errors.New("some error"))). - Error("some message with error level") - require.Contains(t, buf.String(), `lvl=eror msg="some message with error level" error="some error`) -} - -func TestZapLoggerTerminalFormat(t *testing.T) { - buf := bytes.NewBuffer(nil) - logger := log.New() - handler := log.StreamHandler(buf, log.TerminalFormat(false)) - logger.SetHandler(handler) - - zapLogger, err := NewZapLoggerWithAdapter(logger) - require.NoError(t, err) - - zapLogger.Info("some message with error level") - require.Contains(t, buf.String(), `logutils/zap_adapter_test.go:70`) -} diff --git a/mobile/callog/status_request_log.go b/mobile/callog/status_request_log.go index 8873360bb..a0ee4454d 100644 --- a/mobile/callog/status_request_log.go +++ b/mobile/callog/status_request_log.go @@ -9,8 +9,6 @@ import ( "time" "go.uber.org/zap" - - "github.com/status-im/status-go/logutils" ) var sensitiveKeys = []string{ @@ -62,17 +60,17 @@ func getShortFunctionName(fn any) string { // 3. Uses reflection to Call the given function // 4. If request logging is enabled, logs method name, parameters, response, and execution duration // 5. Removes sensitive information before logging -func Call(logger *zap.Logger, fn any, params ...any) any { +func Call(logger, requestLogger *zap.Logger, fn any, params ...any) any { defer func() { if r := recover(); r != nil { - logutils.ZapLogger().Error("panic found in call", zap.Any("error", r), zap.Stack("stacktrace")) + logger.Error("panic found in call", zap.Any("error", r), zap.Stack("stacktrace")) panic(r) } }() var startTime time.Time - requestLoggingEnabled := logger != nil + requestLoggingEnabled := requestLogger != nil if requestLoggingEnabled { startTime = time.Now() } @@ -102,7 +100,7 @@ func Call(logger *zap.Logger, fn any, params ...any) any { paramsString := removeSensitiveInfo(fmt.Sprintf("%+v", params)) respString := removeSensitiveInfo(fmt.Sprintf("%+v", resp)) - logger.Debug("call", + requestLogger.Debug("call", zap.String("method", methodName), zap.String("params", paramsString), zap.String("resp", respString), @@ -113,8 +111,8 @@ func Call(logger *zap.Logger, fn any, params ...any) any { return resp } -func CallWithResponse(logger *zap.Logger, fn any, params ...any) string { - resp := Call(logger, fn, params...) +func CallWithResponse(logger, requestLogger *zap.Logger, fn any, params ...any) string { + resp := Call(logger, requestLogger, fn, params...) if resp == nil { return "" } diff --git a/mobile/callog/status_request_log_test.go b/mobile/callog/status_request_log_test.go index 658ab82f9..ee2a8ffec 100644 --- a/mobile/callog/status_request_log_test.go +++ b/mobile/callog/status_request_log_test.go @@ -1,12 +1,13 @@ package callog import ( - "fmt" + "bytes" "os" "strings" "testing" - "github.com/ethereum/go-ethereum/log" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/stretchr/testify/require" @@ -57,14 +58,22 @@ func TestRemoveSensitiveInfo(t *testing.T) { } func TestCall(t *testing.T) { - // Create a temporary file for logging + // Create default logger + buffer := bytes.NewBuffer(nil) + logger := zap.New(zapcore.NewCore( + zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig()), + zapcore.AddSync(buffer), + zap.DebugLevel, + )) + + // Create a temporary file for request logging tempLogFile, err := os.CreateTemp(t.TempDir(), "TestCall*.log") require.NoError(t, err) // Enable request logging - logger, err := requestlog.CreateRequestLogger(tempLogFile.Name()) + requestLogger, err := requestlog.CreateRequestLogger(tempLogFile.Name()) require.NoError(t, err) - require.NotNil(t, logger) + require.NotNil(t, requestLogger) // Test case 1: Normal execution testFunc := func(param string) string { @@ -73,7 +82,7 @@ func TestCall(t *testing.T) { testParam := "test input" expectedResult := "test result: test input" - result := CallWithResponse(logger, testFunc, testParam) + result := CallWithResponse(logger, requestLogger, testFunc, testParam) // Check the result if result != expectedResult { @@ -83,29 +92,18 @@ func TestCall(t *testing.T) { // Read the log file logData, err := os.ReadFile(tempLogFile.Name()) require.NoError(t, err) - logOutput := string(logData) + requestLogOutput := string(logData) // Check if the log contains expected information expectedLogParts := []string{getShortFunctionName(testFunc), "params", testParam, "resp", expectedResult} for _, part := range expectedLogParts { - if !strings.Contains(logOutput, part) { + if !strings.Contains(requestLogOutput, part) { t.Errorf("Log output doesn't contain expected part: %s", part) } } - // Create a mock logger to capture log output - mockLogger := log.New() - mockLogger.SetHandler(log.FuncHandler(func(r *log.Record) error { - logOutput += r.Msg + fmt.Sprintf("%s", r.Ctx...) - return nil - })) - // Test case 2: Panic -> recovery -> re-panic - oldRootHandler := log.Root().GetHandler() - defer log.Root().SetHandler(oldRootHandler) - log.Root().SetHandler(mockLogger.GetHandler()) - // Clear log output for next test - logOutput = "" + require.Empty(t, buffer.String()) e := "test panic" panicFunc := func() { @@ -113,17 +111,17 @@ func TestCall(t *testing.T) { } require.PanicsWithValue(t, e, func() { - Call(logger, panicFunc) + Call(logger, requestLogger, panicFunc) }) // Check if the panic was logged - if !strings.Contains(logOutput, "panic found in call") { + if !strings.Contains(buffer.String(), "panic found in call") { t.Errorf("Log output doesn't contain panic information") } - if !strings.Contains(logOutput, e) { + if !strings.Contains(buffer.String(), e) { t.Errorf("Log output doesn't contain panic message") } - if !strings.Contains(logOutput, "stacktrace") { + if !strings.Contains(buffer.String(), "stacktrace") { t.Errorf("Log output doesn't contain stacktrace") } } diff --git a/mobile/status.go b/mobile/status.go index 07f34d398..07f8cf0b0 100644 --- a/mobile/status.go +++ b/mobile/status.go @@ -53,11 +53,11 @@ import ( ) func call(fn any, params ...any) any { - return callog.Call(requestlog.GetRequestLogger(), fn, params...) + return callog.Call(logutils.ZapLogger(), requestlog.GetRequestLogger(), fn, params...) } func callWithResponse(fn any, params ...any) string { - return callog.CallWithResponse(requestlog.GetRequestLogger(), fn, params...) + return callog.CallWithResponse(logutils.ZapLogger(), requestlog.GetRequestLogger(), fn, params...) } type InitializeApplicationResponse struct { @@ -2159,7 +2159,7 @@ func InitLogging(logSettingsJSON string) string { return makeJSONResponse(err) } - if err = logutils.OverrideRootLogWithConfig(logSettings.LogSettings, false); err == nil { + if err = logutils.OverrideRootLoggerWithConfig(logSettings.LogSettings); err == nil { logutils.ZapLogger().Info("logging initialised", zap.String("logSettings", logSettingsJSON)) } diff --git a/t/utils/utils.go b/t/utils/utils.go index c0f47c3ae..f6f3106aa 100644 --- a/t/utils/utils.go +++ b/t/utils/utils.go @@ -67,8 +67,11 @@ func Init() { flag.Parse() // set up logger - loggerEnabled := *logLevel != "" - if err := logutils.OverrideRootLog(loggerEnabled, *logLevel, logutils.FileOptions{}, true); err != nil { + err = logutils.OverrideRootLoggerWithConfig(logutils.LogSettings{ + Enabled: *logLevel != "", + Level: *logLevel, + }) + if err != nil { panic(err) }