Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

set logging dest to be stdout, and simplify cmd logging #4588

Merged
merged 11 commits into from
Oct 7, 2024
2 changes: 1 addition & 1 deletion cmd/cli/config/list.go
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ Each key shown can be used with:
if err != nil {
return err
}
log.Info().Msgf("Config loaded from: %s, and with data-dir %s", cfg.Paths(), cfg.Get(types.DataDirKey))
log.Debug().Msgf("Config loaded from: %s, and with data-dir %s", cfg.Paths(), cfg.Get(types.DataDirKey))
return list(cmd, cfg, o)
},
}
Expand Down
5 changes: 2 additions & 3 deletions cmd/cli/devstack/devstack.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import (
"path/filepath"
"strconv"

"github.com/rs/zerolog"
"github.com/rs/zerolog/log"
"github.com/spf13/viper"
"k8s.io/kubectl/pkg/util/i18n"
Expand Down Expand Up @@ -103,9 +104,7 @@ func NewCmd() *cobra.Command {
RunE: func(cmd *cobra.Command, _ []string) error {
// TODO: a hack to force debug logging for devstack
// until I figure out why flags and env vars are not working
if err := logger.ConfigureLogging(string(logger.LogModeDefault), "debug"); err != nil {
return fmt.Errorf("failed to configure logging: %w", err)
}
logger.ConfigureLogging(logger.LogModeDefault, zerolog.DebugLevel)
return runDevstack(cmd, ODs)
},
}
Expand Down
6 changes: 1 addition & 5 deletions cmd/cli/root.go
Original file line number Diff line number Diff line change
Expand Up @@ -76,15 +76,11 @@ func NewRootCmd() *cobra.Command {
// While we allow users to configure logging via the config file, they are applied
// and will override this configuration at a later stage when the config is loaded.
// This is needed to ensure any logs before the config is loaded are captured.
logMode := viper.GetString(types.LoggingModeKey)
if logMode == "" {
logMode = string(logger.LogModeDefault)
}
logLevel := viper.GetString(types.LoggingLevelKey)
if logLevel == "" {
logLevel = "Info"
}
if err := logger.ConfigureLogging(logMode, logLevel); err != nil {
if err := logger.ParseAndConfigureLogging(string(logger.LogModeCmd), logLevel); err != nil {
return fmt.Errorf("failed to configure logging: %w", err)
}

Expand Down
5 changes: 4 additions & 1 deletion cmd/cli/serve/serve.go
Original file line number Diff line number Diff line change
Expand Up @@ -95,6 +95,10 @@ func NewCmd() *cobra.Command {
return fmt.Errorf("failed to setup config: %w", err)
}

if err = logger.ParseAndConfigureLogging(cfg.Logging.Mode, cfg.Logging.Level); err != nil {
return fmt.Errorf("failed to configure logging: %w", err)
}

log.Info().Msgf("Config loaded from: %s, and with data-dir %s",
rawCfg.Paths(), rawCfg.Get(types.DataDirKey))

Expand All @@ -103,7 +107,6 @@ func NewCmd() *cobra.Command {
if err != nil {
return fmt.Errorf("failed to reconcile repo: %w", err)
}

return serve(cmd, cfg, fsr)
},
}
Expand Down
7 changes: 7 additions & 0 deletions cmd/util/repo.go
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ import (
"github.com/bacalhau-project/bacalhau/cmd/util/hook"
"github.com/bacalhau-project/bacalhau/pkg/config"
"github.com/bacalhau-project/bacalhau/pkg/config/types"
"github.com/bacalhau-project/bacalhau/pkg/logger"
"github.com/bacalhau-project/bacalhau/pkg/repo"
"github.com/bacalhau-project/bacalhau/pkg/setup"
)
Expand Down Expand Up @@ -75,6 +76,12 @@ func SetupConfigType(cmd *cobra.Command) (*config.Config, error) {
if err != nil {
return nil, err
}

// We always apply the configured logging level. Logging mode on the other hand is only applied with serve cmd
if err = logger.ParseAndConfigureLoggingLevel(cfg.Get(types.LoggingLevelKey).(string)); err != nil {
return nil, fmt.Errorf("failed to configure logging: %w", err)
}

return cfg, nil
}

Expand Down
121 changes: 65 additions & 56 deletions pkg/logger/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ import (
"runtime/debug"
"strconv"
"strings"
"sync"
"time"

"github.com/rs/zerolog/pkgerrors"
Expand All @@ -29,22 +30,31 @@ type LogMode string

// Available logging modes
const (
LogModeDefault LogMode = "default"
LogModeStation LogMode = "station"
LogModeJSON LogMode = "json"
LogModeCombined LogMode = "combined"
LogModeEvent LogMode = "event"
LogModeDefault LogMode = "default"
LogModeJSON LogMode = "json"
LogModeCmd LogMode = "cmd"
)

var (
logMu sync.Mutex
)

func ParseLogMode(s string) (LogMode, error) {
lm := []LogMode{LogModeDefault, LogModeStation, LogModeJSON, LogModeCombined, LogModeEvent}
lm := []LogMode{LogModeDefault, LogModeJSON, LogModeCmd}
for _, logMode := range lm {
if strings.ToLower(s) == strings.ToLower(string(logMode)) {
return logMode, nil
}
}
return "Error", fmt.Errorf("%q is an invalid log-mode (valid modes: %q)",
s, lm)
return "", fmt.Errorf("%q is an invalid log-mode (valid modes: %q)", s, lm)
}

func ParseLogLevel(s string) (zerolog.Level, error) {
l, err := zerolog.ParseLevel(s)
if err != nil {
return l, fmt.Errorf("%q is an invalid log-level", s)
}
return l, nil
}

var nodeIDFieldName = "NodeID"
Expand All @@ -57,12 +67,14 @@ func init() { //nolint:gochecknoinits
strings.HasSuffix(os.Args[0], ".test") ||
flag.Lookup("test.v") != nil ||
flag.Lookup("test.run") != nil {
configureLogging(zerolog.DebugLevel, defaultLogging())
ConfigureLoggingLevel(zerolog.DebugLevel)
configureLogging(defaultLogging())
return
}

// the default log level when not running a test is ERROR
configureLogging(zerolog.ErrorLevel, bufferLogs())
ConfigureLoggingLevel(zerolog.ErrorLevel)
configureLogging(bufferLogs())
}

func ErrOrDebug(err error) zerolog.Level {
Expand All @@ -82,46 +94,66 @@ type tTesting interface {
func ConfigureTestLogging(t tTesting) {
oldLogger := log.Logger
oldContextLogger := zerolog.DefaultContextLogger
configureLogging(zerolog.DebugLevel, zerolog.NewConsoleWriter(zerolog.ConsoleTestWriter(t), defaultLogFormat))
ConfigureLoggingLevel(zerolog.DebugLevel)
configureLogging(zerolog.NewConsoleWriter(zerolog.ConsoleTestWriter(t), defaultLogFormat))
t.Cleanup(func() {
log.Logger = oldLogger
zerolog.DefaultContextLogger = oldContextLogger
})
}

func ConfigureLogging(modeStr, levelStr string) error {
logModeConfig := defaultLogging()

func ParseAndConfigureLogging(modeStr, levelStr string) error {
mode, err := ParseLogMode(modeStr)
if err != nil {
return fmt.Errorf("invalid log mode: %w", err)
return err
}
level, err := zerolog.ParseLevel(levelStr)
level, err := ParseLogLevel(levelStr)
if err != nil {
return fmt.Errorf("invalid log level: %w", err)
return err
}

ConfigureLogging(mode, level)
return nil
}

func ConfigureLogging(mode LogMode, level zerolog.Level) {
var logWriter io.Writer
switch mode {
case LogModeDefault:
logModeConfig = defaultLogging()
case LogModeStation:
logModeConfig = defaultStationLogging()
logWriter = defaultLogging()
case LogModeJSON:
logModeConfig = jsonLogging()
case LogModeEvent:
logModeConfig = eventLogging()
case LogModeCombined:
logModeConfig = combinedLogging()
logWriter = jsonLogging()
case LogModeCmd:
logWriter = clientLogging()
default:
logWriter = defaultLogging()
}
configureLogging(level, logModeConfig)

LogBufferedLogs(logModeConfig)
ConfigureLoggingLevel(level)
configureLogging(logWriter)
LogBufferedLogs(logWriter)
}

func ParseAndConfigureLoggingLevel(level string) error {
l, err := ParseLogLevel(level)
if err != nil {
return err
}
ConfigureLoggingLevel(l)
return nil
}

func configureLogging(level zerolog.Level, logWriter io.Writer) {
zerolog.TimeFieldFormat = time.RFC3339Nano
func ConfigureLoggingLevel(level zerolog.Level) {
logMu.Lock()
defer logMu.Unlock()
zerolog.SetGlobalLevel(level)
}

func configureLogging(logWriter io.Writer) {
logMu.Lock()
defer logMu.Unlock()

zerolog.TimeFieldFormat = time.RFC3339Nano

info, ok := debug.ReadBuildInfo()
if ok && info.Main.Path != "" {
Expand All @@ -148,21 +180,13 @@ func jsonLogging() io.Writer {
return os.Stdout
}

func eventLogging() io.Writer {
return io.Discard
}

func combinedLogging() io.Writer {
return zerolog.MultiLevelWriter(defaultLogging(), os.Stdout)
}

func defaultLogging() io.Writer {
return zerolog.NewConsoleWriter(defaultLogFormat)
}

func defaultLogFormat(w *zerolog.ConsoleWriter) {
isTerminal := isatty.IsTerminal(os.Stdout.Fd())
w.Out = os.Stderr
w.Out = os.Stdout
w.NoColor = !isTerminal
w.TimeFormat = "15:04:05.999 |"
w.PartsOrder = []string{
Expand All @@ -187,25 +211,10 @@ func defaultLogFormat(w *zerolog.ConsoleWriter) {
}
}

func defaultStationLogging() io.Writer {
func clientLogging() io.Writer {
return zerolog.NewConsoleWriter(func(w *zerolog.ConsoleWriter) {
isTerminal := isatty.IsTerminal(os.Stdout.Fd())
w.Out = os.Stdout
w.NoColor = !isTerminal
w.PartsOrder = []string{
zerolog.LevelFieldName,
zerolog.MessageFieldName,
}

w.FormatLevel = func(i interface{}) string {
return strings.ToUpper(i.(string)) + ":"
}
w.FormatErrFieldName = func(i interface{}) string {
return "- "
}
w.FormatErrFieldValue = func(i interface{}) string {
return strings.Trim(i.(string), "\"")
}
defaultLogFormat(w)
w.PartsOrder = []string{zerolog.MessageFieldName}
})
}

Expand Down
66 changes: 65 additions & 1 deletion pkg/logger/logger_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,8 @@ func TestConfigureLogging(t *testing.T) {
})

var logging strings.Builder
configureLogging(zerolog.InfoLevel, zerolog.NewConsoleWriter(func(w *zerolog.ConsoleWriter) {
ConfigureLoggingLevel(zerolog.InfoLevel)
configureLogging(zerolog.NewConsoleWriter(func(w *zerolog.ConsoleWriter) {
defaultLogFormat(w)
w.Out = &logging
w.NoColor = true
Expand All @@ -40,3 +41,66 @@ func TestConfigureLogging(t *testing.T) {
assert.Contains(t, actual, "pkg/logger/testpackage/subpackage/subsubpackage/testutil.go", "Log statement doesn't contain the full package path")
assert.Contains(t, actual, `stack:[{"func":"TestLog","line":`, "Log statement didn't automatically include the error's stacktrace")
}

func TestParseAndConfigureLogging(t *testing.T) {
err := ParseAndConfigureLogging("default", "debug")
assert.NoError(t, err)
assert.Equal(t, zerolog.DebugLevel, zerolog.GlobalLevel())

err = ParseAndConfigureLogging("json", "info")
assert.NoError(t, err)
assert.Equal(t, zerolog.InfoLevel, zerolog.GlobalLevel())

err = ParseAndConfigureLogging("invalid", "error")
assert.Error(t, err)

err = ParseAndConfigureLogging("default", "invalid")
assert.Error(t, err)
}

func TestParseLogMode(t *testing.T) {
tests := []struct {
input string
expected LogMode
hasError bool
}{
{"default", LogModeDefault, false},
{"json", LogModeJSON, false},
{"cmd", LogModeCmd, false},
{"invalid", "", true},
}

for _, test := range tests {
result, err := ParseLogMode(test.input)
if test.hasError {
assert.Error(t, err)
} else {
assert.NoError(t, err)
assert.Equal(t, test.expected, result)
}
}
}

func TestParseLogLevel(t *testing.T) {
tests := []struct {
input string
expected zerolog.Level
hasError bool
}{
{"debug", zerolog.DebugLevel, false},
{"info", zerolog.InfoLevel, false},
{"warn", zerolog.WarnLevel, false},
{"error", zerolog.ErrorLevel, false},
{"invalid", zerolog.NoLevel, true},
}

for _, test := range tests {
result, err := ParseLogLevel(test.input)
if test.hasError {
assert.Error(t, err)
} else {
assert.NoError(t, err)
assert.Equal(t, test.expected, result)
}
}
}
4 changes: 0 additions & 4 deletions pkg/setup/setup.go
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,6 @@ import (

"github.com/bacalhau-project/bacalhau/pkg/config"
"github.com/bacalhau-project/bacalhau/pkg/config/types"
"github.com/bacalhau-project/bacalhau/pkg/logger"
"github.com/bacalhau-project/bacalhau/pkg/repo/migrations"

"github.com/bacalhau-project/bacalhau/pkg/repo"
Expand All @@ -25,9 +24,6 @@ func SetupMigrationManager() (*repo.MigrationManager, error) {

// SetupBacalhauRepo ensures that a bacalhau repo and config exist and are initialized.
func SetupBacalhauRepo(cfg types.Bacalhau) (*repo.FsRepo, error) {
if err := logger.ConfigureLogging(cfg.Logging.Mode, cfg.Logging.Level); err != nil {
return nil, fmt.Errorf("failed to configure logging: %w", err)
}
migrationManger, err := SetupMigrationManager()
if err != nil {
return nil, fmt.Errorf("failed to create migration manager: %w", err)
Expand Down
Loading