diff --git a/changelog/unreleased/fix-logging-levels.md b/changelog/unreleased/fix-logging-levels.md new file mode 100644 index 00000000000..3e0b33b021d --- /dev/null +++ b/changelog/unreleased/fix-logging-levels.md @@ -0,0 +1,15 @@ +Bugfix: Fix logging levels + +We've fixed the configuration of logging levels. Previously it was not possible +to configure a service with a more or less verbose log level then all other services +when running in the supervised / runtime mode `ocis server`. + +For example `OCIS_LOG_LEVEL=error PROXY_LOG_LEVEL=debug ocis server` did not configure +error logging for all services except the proxy, which should be on debug logging. This is now fixed +and working properly. + +Also we fixed the format of go-micro logs to always default to error level. +Previously this was only ensured in the supervised / runtime mode. + +https://github.com/owncloud/ocis/pull/4102 +https://github.com/owncloud/ocis/issues/4089 diff --git a/ocis-pkg/log/log.go b/ocis-pkg/log/log.go index ea33f50741c..14a89d5ea85 100644 --- a/ocis-pkg/log/log.go +++ b/ocis-pkg/log/log.go @@ -6,15 +6,37 @@ import ( "strings" "time" + mzlog "github.com/go-micro/plugins/v4/logger/zerolog" "github.com/owncloud/ocis/v2/ocis-pkg/shared" - "github.com/rs/zerolog" "github.com/rs/zerolog/log" - mdlog "go-micro.dev/v4/debug/log" - mlog "go-micro.dev/v4/util/log" - "go-micro.dev/v4/util/ring" + "go-micro.dev/v4/logger" ) +func init() { + // this is ugly, but "logger.DefaultLogger" is a global variable and we need to set it _before_ anybody uses it + setMicroLogger() +} + +// for logging reasons we don't want the same logging level on both oCIS and micro. As a framework builder we do not +// want to expose to the end user the internal framework logs unless explicitly specified. +func setMicroLogger() { + if os.Getenv("MICRO_LOG_LEVEL") == "" { + _ = os.Setenv("MICRO_LOG_LEVEL", "error") + } + + lev, err := zerolog.ParseLevel(os.Getenv("MICRO_LOG_LEVEL")) + if err != nil { + lev = zerolog.ErrorLevel + } + logger.DefaultLogger = mzlog.NewLogger( + logger.WithLevel(logger.Level(lev)), + logger.WithFields(map[string]interface{}{ + "system": "go-micro", + }), + ) +} + // Logger simply wraps the zerolog logger. type Logger struct { zerolog.Logger @@ -35,31 +57,27 @@ func LoggerFromConfig(name string, cfg *shared.Log) Logger { func NewLogger(opts ...Option) Logger { options := newOptions(opts...) + // set GlobalLevel() to the minimum value -1 = TraceLevel, so that only the services' log level matter + zerolog.SetGlobalLevel(zerolog.TraceLevel) + + var logLevel zerolog.Level switch strings.ToLower(options.Level) { case "panic": - zerolog.SetGlobalLevel(zerolog.PanicLevel) - mlog.SetLevel(mlog.LevelFatal) + logLevel = zerolog.PanicLevel case "fatal": - zerolog.SetGlobalLevel(zerolog.FatalLevel) - mlog.SetLevel(mlog.LevelFatal) + logLevel = zerolog.FatalLevel case "error": - zerolog.SetGlobalLevel(zerolog.ErrorLevel) - mlog.SetLevel(mlog.LevelError) + logLevel = zerolog.ErrorLevel case "warn": - zerolog.SetGlobalLevel(zerolog.WarnLevel) - mlog.SetLevel(mlog.LevelWarn) + logLevel = zerolog.WarnLevel case "info": - zerolog.SetGlobalLevel(zerolog.InfoLevel) - mlog.SetLevel(mlog.LevelInfo) + logLevel = zerolog.InfoLevel case "debug": - zerolog.SetGlobalLevel(zerolog.DebugLevel) - mlog.SetLevel(mlog.LevelDebug) + logLevel = zerolog.DebugLevel case "trace": - zerolog.SetGlobalLevel(zerolog.DebugLevel) - mlog.SetLevel(mlog.LevelTrace) + logLevel = zerolog.TraceLevel default: - zerolog.SetGlobalLevel(zerolog.ErrorLevel) - mlog.SetLevel(mlog.LevelError) + logLevel = zerolog.ErrorLevel } var logger zerolog.Logger @@ -88,105 +106,9 @@ func NewLogger(opts ...Option) Logger { logger = logger.With(). Str("service", options.Name). Timestamp(). - Logger() - - mlog.SetLogger( - microZerolog{ - logger: logger, - buffer: ring.New(mdlog.DefaultSize), - }, - ) + Logger().Level(logLevel) return Logger{ logger, } } - -// microZerolog implements the required interface for the go-micro logger. -type microZerolog struct { - logger zerolog.Logger - buffer *ring.Buffer -} - -func (mz microZerolog) Read(opts ...mdlog.ReadOption) ([]mdlog.Record, error) { - options := mdlog.ReadOptions{} - for _, o := range opts { - o(&options) - } - - var entries []*ring.Entry - - if !options.Since.IsZero() { - entries = mz.buffer.Since(options.Since) - } - - if options.Count > 0 { - switch len(entries) > 0 { - case true: - if options.Count > len(entries) { - entries = entries[0:options.Count] - } - default: - entries = mz.buffer.Get(options.Count) - } - } - - records := make([]mdlog.Record, 0, len(entries)) - for _, entry := range entries { - record := mdlog.Record{ - Timestamp: entry.Timestamp, - Message: entry.Value, - } - records = append(records, record) - } - - return records, nil -} - -func (mz microZerolog) Write(record mdlog.Record) error { - level := record.Metadata["level"] - mz.log(level, fmt.Sprint(record.Message)) - mz.buffer.Put(record.Message) - return nil -} - -func (mz microZerolog) Stream() (mdlog.Stream, error) { - stream, stop := mz.buffer.Stream() - records := make(chan mdlog.Record, 128) - last10 := mz.buffer.Get(10) - - go func() { - for _, entry := range last10 { - records <- mdlog.Record{ - Timestamp: entry.Timestamp, - Message: entry.Value, - Metadata: make(map[string]string), - } - } - for entry := range stream { - records <- mdlog.Record{ - Timestamp: entry.Timestamp, - Message: entry.Value, - Metadata: make(map[string]string), - } - } - }() - return &logStream{ - stream: records, - stop: stop, - }, nil -} - -func (mz microZerolog) log(level string, msg string) { - l, err := zerolog.ParseLevel(level) - if err != nil { - l = zerolog.InfoLevel - } - - mz.logger.WithLevel(l).Msg(msg) - - // Invoke os.Exit because unlike zerolog.Logger.Fatal zerolog.Logger.WithLevel won't stop the execution. - if l == zerolog.FatalLevel { - os.Exit(1) - } -} diff --git a/ocis/pkg/runtime/service/service.go b/ocis/pkg/runtime/service/service.go index dc5e76bfdbd..2cc5a3e3db7 100644 --- a/ocis/pkg/runtime/service/service.go +++ b/ocis/pkg/runtime/service/service.go @@ -15,7 +15,6 @@ import ( "github.com/owncloud/ocis/v2/ocis-pkg/shared" - mzlog "github.com/go-micro/plugins/v4/logger/zerolog" "github.com/mohae/deepcopy" "github.com/olekukonko/tablewriter" @@ -50,9 +49,7 @@ import ( users "github.com/owncloud/ocis/v2/services/users/pkg/command" web "github.com/owncloud/ocis/v2/services/web/pkg/command" webdav "github.com/owncloud/ocis/v2/services/webdav/pkg/command" - "github.com/rs/zerolog" "github.com/thejerf/suture/v4" - "go-micro.dev/v4/logger" ) var ( @@ -157,8 +154,6 @@ func Start(o ...Option) error { halt := make(chan os.Signal, 1) signal.Notify(halt, syscall.SIGINT, syscall.SIGTERM, syscall.SIGQUIT, syscall.SIGHUP) - setMicroLogger() - // tolerance controls backoff cycles from the supervisor. tolerance := 5 totalBackoff := 0 @@ -301,17 +296,3 @@ func trap(s *Service, halt chan os.Signal) { s.Log.Debug().Str("service", "runtime service").Msgf("terminating with signal: %v", s) os.Exit(0) } - -// for logging reasons we don't want the same logging level on both oCIS and micro. As a framework builder we do not -// want to expose to the end user the internal framework logs unless explicitly specified. -func setMicroLogger() { - if os.Getenv("MICRO_LOG_LEVEL") == "" { - _ = os.Setenv("MICRO_LOG_LEVEL", "error") - } - - lev, err := zerolog.ParseLevel(os.Getenv("MICRO_LOG_LEVEL")) - if err != nil { - lev = zerolog.ErrorLevel - } - logger.DefaultLogger = mzlog.NewLogger(logger.WithLevel(logger.Level(lev))) -}