secureworks/logger

Logger silently drops msgs when multiple .Msgf() calles are made

omnisis opened this issue · 1 comments

When doing logging with either zerolog or logrus, it is common to have a "parent" context established and "add to it" buy creating a child log entry/context and making subsequent msg calls from it. This example is explicitly mentioned in the logrus docs:

 // A common pattern is to re-use fields between logging statements by re-using
  // the logrus.Entry returned from WithFields()
  contextLogger := log.WithFields(log.Fields{
    "common": "this is a common field",
    "other": "I also should be logged always",
  })

  contextLogger.Info("I'll be logged with common and other field")
  contextLogger.Info("Me too")

and the zerolog docs:

sublogger := log.With().
                 Str("component", "foo").
                 Logger()
sublogger.Info().Msg("hello world")

You'll note that in the case of zerolog, one has to call Logger() to explicitly convert the zerolog.Context object into a zerolog.Logger that can then be chained on with Info/Error/Debug/Trace just like a top-level logger object.

The closest scwx logger analogue is the following:

l := logger.WithField("app", "cool-app").WithField("cluster", "cluster-0001")
l.Info().Msg("log msg 1")
l.Info().WithField("filename", "foo.zip").Msg("log msg 2")

When the above code is run the output is:

{"app":"cool-app","cluster":"cluster-0001","level":"info","message":"log msg 1"}

While the expected output (based on both log libraries default behavior) is

{"app":"cool-app","cluster":"cluster-0001","level":"info","message":"log msg 1"}
{"app":"cool-app","cluster":"cluster-0001","filename":"foo.zip","level":"info","message":"log msg 2"}

In addition there is a lack of parity between calling .Msg() repeatedly on a log.Entry and a log.Logger instance. In that

logger.Info().Msg("log msg 1")
logger.Info().Msg("log msg 2")

will print both log msgs but

l := logger.WithField("app", "cool-app")
l.Info().Msg("log msg 1")
l.Info().Msg("log msg 2")

will only ever print the first log msg.

Given that this is a common use-case in both logging libraries, it should work as expected in this logging library as well.

hews commented

Discussion moved to #11.