fix logging levels and go-micro logging format

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

ocis-pkg/log/gomicro/log.go

@@ -0,0 +1,33 @@
+package gomicro
+
+import (
+	"os"
+
+	mzlog "github.com/go-micro/plugins/v4/logger/zerolog"
+	"github.com/rs/zerolog"
+	"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",
+		}),
+	)
+}

ocis-pkg/log/log.go

@@ -10,9 +10,6 @@ import (
 
 	"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"
 )
 
 // Logger simply wraps the zerolog logger.
@@ -35,31 +32,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)
+		logLevel = zerolog.PanicLevel
-		mlog.SetLevel(mlog.LevelFatal)
 	case "fatal":
-		zerolog.SetGlobalLevel(zerolog.FatalLevel)
+		logLevel = zerolog.FatalLevel
-		mlog.SetLevel(mlog.LevelFatal)
 	case "error":
-		zerolog.SetGlobalLevel(zerolog.ErrorLevel)
+		logLevel = zerolog.ErrorLevel
-		mlog.SetLevel(mlog.LevelError)
 	case "warn":
-		zerolog.SetGlobalLevel(zerolog.WarnLevel)
+		logLevel = zerolog.WarnLevel
-		mlog.SetLevel(mlog.LevelWarn)
 	case "info":
-		zerolog.SetGlobalLevel(zerolog.InfoLevel)
+		logLevel = zerolog.InfoLevel
-		mlog.SetLevel(mlog.LevelInfo)
 	case "debug":
-		zerolog.SetGlobalLevel(zerolog.DebugLevel)
+		logLevel = zerolog.DebugLevel
-		mlog.SetLevel(mlog.LevelDebug)
 	case "trace":
-		zerolog.SetGlobalLevel(zerolog.DebugLevel)
+		logLevel = zerolog.TraceLevel
-		mlog.SetLevel(mlog.LevelTrace)
 	default:
-		zerolog.SetGlobalLevel(zerolog.ErrorLevel)
+		logLevel = zerolog.ErrorLevel
-		mlog.SetLevel(mlog.LevelError)
 	}
 
 	var logger zerolog.Logger
@@ -88,105 +81,9 @@ func NewLogger(opts ...Option) Logger {
 	logger = logger.With().
 		Str("service", options.Name).
 		Timestamp().
-		Logger()
+		Logger().Level(logLevel)
-
-	mlog.SetLogger(
-		microZerolog{
-			logger: logger,
-			buffer: ring.New(mdlog.DefaultSize),
-		},
-	)
 
 	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)
-	}
-}

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,9 @@ 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"
+
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 )
 
 var (
@@ -157,8 +156,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 +298,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)))
-}

services/app-provider/cmd/app-provider/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/app-provider/pkg/command"
 	"github.com/owncloud/ocis/v2/services/app-provider/pkg/config/defaults"
 )

services/app-registry/cmd/app-registry/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/app-registry/pkg/command"
 	"github.com/owncloud/ocis/v2/services/app-registry/pkg/config/defaults"
 )

services/audit/cmd/audit/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/audit/pkg/command"
 	"github.com/owncloud/ocis/v2/services/audit/pkg/config/defaults"
 )

services/auth-basic/cmd/auth-basic/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/auth-basic/pkg/command"
 	"github.com/owncloud/ocis/v2/services/auth-basic/pkg/config/defaults"
 )

services/auth-bearer/cmd/auth-bearer/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/auth-bearer/pkg/command"
 	"github.com/owncloud/ocis/v2/services/auth-bearer/pkg/config/defaults"
 )

services/auth-machine/cmd/auth-machine/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/auth-machine/pkg/command"
 	"github.com/owncloud/ocis/v2/services/auth-machine/pkg/config/defaults"
 )

services/frontend/cmd/frontend/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/frontend/pkg/command"
 	"github.com/owncloud/ocis/v2/services/frontend/pkg/config/defaults"
 )

services/gateway/cmd/gateway/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/gateway/pkg/command"
 	"github.com/owncloud/ocis/v2/services/gateway/pkg/config/defaults"
 )

services/graph-explorer/cmd/graph-explorer/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/graph-explorer/pkg/command"
 	"github.com/owncloud/ocis/v2/services/graph-explorer/pkg/config/defaults"
 )

services/graph/cmd/graph/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/graph/pkg/command"
 	"github.com/owncloud/ocis/v2/services/graph/pkg/config/defaults"
 )

services/groups/cmd/groups/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/groups/pkg/command"
 	"github.com/owncloud/ocis/v2/services/groups/pkg/config/defaults"
 )

services/idm/cmd/idm/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/idm/pkg/command"
 	"github.com/owncloud/ocis/v2/services/idm/pkg/config/defaults"
 )

services/idp/cmd/idp/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/idp/pkg/command"
 	"github.com/owncloud/ocis/v2/services/idp/pkg/config/defaults"
 )

services/nats/cmd/nats/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/nats/pkg/command"
 	"github.com/owncloud/ocis/v2/services/nats/pkg/config/defaults"
 )

services/notifications/cmd/notifications/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/notifications/pkg/command"
 	"github.com/owncloud/ocis/v2/services/notifications/pkg/config/defaults"
 )

services/ocdav/cmd/ocdav/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/ocdav/pkg/command"
 	"github.com/owncloud/ocis/v2/services/ocdav/pkg/config/defaults"
 )

services/ocs/cmd/ocs/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/ocs/pkg/command"
 	"github.com/owncloud/ocis/v2/services/ocs/pkg/config/defaults"
 )

services/proxy/cmd/proxy/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/proxy/pkg/command"
 	"github.com/owncloud/ocis/v2/services/proxy/pkg/config/defaults"
 )

services/search/cmd/search/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/search/pkg/command"
 	"github.com/owncloud/ocis/v2/services/search/pkg/config/defaults"
 )

services/settings/cmd/settings/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/settings/pkg/command"
 	"github.com/owncloud/ocis/v2/services/settings/pkg/config/defaults"
 )

services/sharing/cmd/sharing/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/sharing/pkg/command"
 	"github.com/owncloud/ocis/v2/services/sharing/pkg/config/defaults"
 )

services/storage-publiclink/cmd/storage-publiclink/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/storage-publiclink/pkg/command"
 	"github.com/owncloud/ocis/v2/services/storage-publiclink/pkg/config/defaults"
 )

services/storage-shares/cmd/storage-shares/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/storage-shares/pkg/command"
 	"github.com/owncloud/ocis/v2/services/storage-shares/pkg/config/defaults"
 )

services/storage-system/cmd/storage-system/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/storage-system/pkg/command"
 	"github.com/owncloud/ocis/v2/services/storage-system/pkg/config/defaults"
 )

services/storage-users/cmd/storage-users/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/storage-users/pkg/command"
 	"github.com/owncloud/ocis/v2/services/storage-users/pkg/config/defaults"
 )

services/store/cmd/store/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/store/pkg/command"
 	"github.com/owncloud/ocis/v2/services/store/pkg/config/defaults"
 )

services/thumbnails/cmd/thumbnails/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/thumbnails/pkg/command"
 	"github.com/owncloud/ocis/v2/services/thumbnails/pkg/config/defaults"
 )

services/users/cmd/user/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/users/pkg/command"
 	"github.com/owncloud/ocis/v2/services/users/pkg/config/defaults"
 )

services/web/cmd/web/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/web/pkg/command"
 	"github.com/owncloud/ocis/v2/services/web/pkg/config/defaults"
 )

services/webdav/cmd/webdav/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"os"
 
+	_ "github.com/owncloud/ocis/v2/ocis-pkg/log/gomicro"
 	"github.com/owncloud/ocis/v2/services/webdav/pkg/command"
 	"github.com/owncloud/ocis/v2/services/webdav/pkg/config/defaults"
 )