From 7f6cda48e76608398661315311bf328466af1d71 Mon Sep 17 00:00:00 2001 From: Silas Davis <silas@erisindustries.com> Date: Wed, 17 May 2017 20:14:06 +0100 Subject: [PATCH] Step back from (that is remove) the notion of two independent channels. Adds a lot of complexity and the same value can be better satisfied by the sinks mechanism (just filter). --- config/templates.go | 10 ++-- glide.lock | 2 +- glide.yaml | 2 +- logging/config/config.go | 9 ++-- logging/config/config_test.go | 4 +- logging/config/sinks.go | 4 +- logging/lifecycle/lifecycle.go | 30 +++++------ logging/loggers/info_trace_logger.go | 63 ++++++++++------------- logging/loggers/info_trace_logger_test.go | 2 +- logging/types/info_trace_logger.go | 23 +++------ 10 files changed, 58 insertions(+), 91 deletions(-) diff --git a/config/templates.go b/config/templates.go index e31558ab..f7f06efa 100644 --- a/config/templates.go +++ b/config/templates.go @@ -310,10 +310,7 @@ const sectionLoggingHeader = ` ## ## Log messages are sent to one of two 'channels': info or trace ## -## They are delivered on two independent streams: 'info' or 'info and trace'. -## Each of these streams has a root logging 'sink' (configured under the keys -## logging.info_sink and logging.info_and_trace_sink respectively) where each -## channels messages are delivered. +## They are delivered on a single non-blocking stream to a 'root sink'. ## ## A sink may optionally define any of a 'transform', an 'output', and a list of ## downstream sinks. Log messages flow through a sink by first having that @@ -329,9 +326,8 @@ const sectionLoggingHeader = ` ## A minimal logging config for multi-line, colourised terminal output would be: # # [logging] -# [logging.info_sink] -# [logging.info_and_trace_sink] -# [logging.info_and_trace_sink.output] +# [logging.root_sink] +# [logging.root_sink.output] # output_type = "stderr" # format = "terminal" ` diff --git a/glide.lock b/glide.lock index a53f4588..c807e294 100644 --- a/glide.lock +++ b/glide.lock @@ -39,7 +39,7 @@ imports: - binding - render - name: github.com/go-kit/kit - version: f66b0e13579bfc5a48b9e2a94b1209c107ea1f41 + version: fadad6fffe0466b19df9efd9acde5c9a52df5fa4 subpackages: - log - name: github.com/go-logfmt/logfmt diff --git a/glide.yaml b/glide.yaml index cb5cf944..7a2af8d0 100644 --- a/glide.yaml +++ b/glide.yaml @@ -17,7 +17,7 @@ import: subpackages: - http2 - package: github.com/go-kit/kit - version: ^0.3.0 + version: ~0.4.0 - package: github.com/eapache/channels version: ~1.1.0 - package: github.com/go-logfmt/logfmt diff --git a/logging/config/config.go b/logging/config/config.go index fb84f43b..81b8b841 100644 --- a/logging/config/config.go +++ b/logging/config/config.go @@ -10,8 +10,7 @@ import ( ) type LoggingConfig struct { - InfoSink *SinkConfig `toml:"info_sink"` - InfoAndTraceSink *SinkConfig `toml:"info_and_trace_sink"` + RootSink *SinkConfig `toml:"root_sink,omitempty"` } // For encoding a top-level '[logging]' TOML table @@ -21,19 +20,17 @@ type LoggingConfigWrapper struct { func DefaultNodeLoggingConfig() *LoggingConfig { return &LoggingConfig{ - InfoSink: Sink(), - InfoAndTraceSink: Sink().SetOutput(StderrOutput()), + RootSink: Sink().SetOutput(StderrOutput()), } } func DefaultClientLoggingConfig() *LoggingConfig { return &LoggingConfig{ // No output - InfoSink: Sink(). + RootSink: Sink(). SetTransform(FilterTransform(ExcludeWhenAnyMatches, structure.CapturedLoggingSourceKey, "")). SetOutput(StderrOutput()), - InfoAndTraceSink: Sink(), } } diff --git a/logging/config/config_test.go b/logging/config/config_test.go index 5e30c751..de53dd3a 100644 --- a/logging/config/config_test.go +++ b/logging/config/config_test.go @@ -10,9 +10,7 @@ import ( ) var complexConfig *LoggingConfig = &LoggingConfig{ - InfoSink: Sink(). - SetOutput(StderrOutput()), - InfoAndTraceSink: Sink(). + RootSink: Sink(). SetTransform(LabelTransform(false, "Info", "Trace")). AddSinks( Sink(). diff --git a/logging/config/sinks.go b/logging/config/sinks.go index 7eaea511..b12ca85a 100644 --- a/logging/config/sinks.go +++ b/logging/config/sinks.go @@ -342,9 +342,9 @@ func BuildTransformLogger(transformConfig *TransformConfig, keyvals = append(keyvals, k, v) } if transformConfig.LabelConfig.Prefix { - return kitlog.NewContext(outputLogger).WithPrefix(keyvals...), captures, nil + return kitlog.WithPrefix(outputLogger, keyvals...), captures, nil } else { - return kitlog.NewContext(outputLogger).With(keyvals...), captures, nil + return kitlog.With(outputLogger, keyvals...), captures, nil } case Prune: keys := make([]interface{}, len(transformConfig.PruneConfig.Keys)) diff --git a/logging/lifecycle/lifecycle.go b/logging/lifecycle/lifecycle.go index ab1c4f54..c8f7f8cd 100644 --- a/logging/lifecycle/lifecycle.go +++ b/logging/lifecycle/lifecycle.go @@ -41,35 +41,33 @@ func NewLoggerFromLoggingConfig(loggingConfig *config.LoggingConfig) (types.Info if loggingConfig == nil { return NewStdErrLogger(), nil } - infoOnlyLogger, infoAndTraceLogger, err := infoTraceLoggersFromLoggingConfig(loggingConfig) + outputLogger, err := infoTraceLoggerFromLoggingConfig(loggingConfig) if err != nil { return nil, err } - return NewLogger(infoOnlyLogger, infoAndTraceLogger), nil + return NewLogger(outputLogger), nil } // Hot swap logging config by replacing output loggers of passed InfoTraceLogger // with those built from loggingConfig func SwapOutputLoggersFromLoggingConfig(logger types.InfoTraceLogger, loggingConfig *config.LoggingConfig) error { - infoOnlyLogger, infoAndTraceLogger, err := infoTraceLoggersFromLoggingConfig(loggingConfig) + outputLogger, err := infoTraceLoggerFromLoggingConfig(loggingConfig) if err != nil { return err } - logger.SwapInfoOnlyOutput(infoOnlyLogger) - logger.SwapInfoAndTraceOutput(infoAndTraceLogger) + logger.SwapOutput(outputLogger) return nil } func NewStdErrLogger() types.InfoTraceLogger { logger := loggers.NewStreamLogger(os.Stderr, "terminal") - return NewLogger(nil, logger) + return NewLogger(logger) } -// Provided a standard logger that outputs to the supplied underlying info -// and trace loggers -func NewLogger(infoOnlyLogger, infoAndTraceLogger kitlog.Logger) types.InfoTraceLogger { - infoTraceLogger := loggers.NewInfoTraceLogger(infoOnlyLogger, infoAndTraceLogger) +// Provided a standard logger that outputs to the supplied underlying outputLogger +func NewLogger(outputLogger kitlog.Logger) types.InfoTraceLogger { + infoTraceLogger := loggers.NewInfoTraceLogger(outputLogger) // Create a random ID based on start time uuid, _ := simpleuuid.NewTime(time.Now()) var runId string @@ -91,14 +89,10 @@ func CaptureStdlibLogOutput(infoTraceLogger types.InfoTraceLogger) { } // Helpers -func infoTraceLoggersFromLoggingConfig(loggingConfig *config.LoggingConfig) (kitlog.Logger, kitlog.Logger, error) { - infoOnlyLogger, _, err := loggingConfig.InfoSink.BuildLogger() +func infoTraceLoggerFromLoggingConfig(loggingConfig *config.LoggingConfig) (kitlog.Logger, error) { + outputLogger, _, err := loggingConfig.RootSink.BuildLogger() if err != nil { - return nil, nil, err - } - infoAndTraceLogger, _, err := loggingConfig.InfoAndTraceSink.BuildLogger() - if err != nil { - return nil, nil, err + return nil, err } - return infoOnlyLogger, infoAndTraceLogger, nil + return outputLogger, nil } diff --git a/logging/loggers/info_trace_logger.go b/logging/loggers/info_trace_logger.go index 2ad14e1d..341e907d 100644 --- a/logging/loggers/info_trace_logger.go +++ b/logging/loggers/info_trace_logger.go @@ -21,32 +21,30 @@ import ( ) type infoTraceLogger struct { - infoOnly *kitlog.Context - infoAndTrace *kitlog.Context - infoOnlyOutputLogger *kitlog.SwapLogger - infoAndTraceOutputLogger *kitlog.SwapLogger + infoContext kitlog.Logger + traceContext kitlog.Logger + outputLogger *kitlog.SwapLogger } // Interface assertions var _ types.InfoTraceLogger = (*infoTraceLogger)(nil) var _ kitlog.Logger = (types.InfoTraceLogger)(nil) -// Create an InfoTraceLogger by passing the initial ouput loggers. The infoOnlyLogger will only be sent messages from -// the Info channel. The infoAndTraceLogger will be sent messages from both the Info and Trace channels. -func NewInfoTraceLogger(infoOnlyLogger, infoAndTraceLogger kitlog.Logger) types.InfoTraceLogger { +// Create an InfoTraceLogger by passing the initial outputLogger. +func NewInfoTraceLogger(outputLogger kitlog.Logger) types.InfoTraceLogger { // We will never halt the progress of a log emitter. If log output takes too // long will start dropping log lines by using a ring buffer. - var infoOnlyOutputLogger, infoAndTraceOutputLogger kitlog.SwapLogger - infoOnlyOutputLogger.Swap(infoOnlyLogger) - infoAndTraceOutputLogger.Swap(infoAndTraceLogger) + swapLogger := new(kitlog.SwapLogger) + swapLogger.Swap(outputLogger) + wrappedOutputLogger := wrapOutputLogger(swapLogger) return &infoTraceLogger{ - infoOnlyOutputLogger: &infoOnlyOutputLogger, - infoAndTraceOutputLogger: &infoAndTraceOutputLogger, - infoOnly: wrapOutputLogger(&infoOnlyOutputLogger).With( + outputLogger: swapLogger, + // logging contexts + infoContext: kitlog.With(wrappedOutputLogger, structure.ChannelKey, types.InfoChannelName, structure.LevelKey, types.InfoLevelName, ), - infoAndTrace: wrapOutputLogger(&infoAndTraceOutputLogger).With( + traceContext: kitlog.With(wrappedOutputLogger, structure.ChannelKey, types.TraceChannelName, structure.LevelKey, types.TraceLevelName, ), @@ -54,42 +52,35 @@ func NewInfoTraceLogger(infoOnlyLogger, infoAndTraceLogger kitlog.Logger) types. } func NewNoopInfoTraceLogger() types.InfoTraceLogger { - return NewInfoTraceLogger(nil, nil) + return NewInfoTraceLogger(nil) } func (l *infoTraceLogger) With(keyvals ...interface{}) types.InfoTraceLogger { return &infoTraceLogger{ - infoOnly: l.infoOnly.With(keyvals...), - infoAndTrace: l.infoAndTrace.With(keyvals...), + outputLogger: l.outputLogger, + infoContext: kitlog.With(l.infoContext, keyvals...), + traceContext: kitlog.With(l.traceContext, keyvals...), } } func (l *infoTraceLogger) WithPrefix(keyvals ...interface{}) types.InfoTraceLogger { return &infoTraceLogger{ - infoOnly: l.infoOnly.WithPrefix(keyvals...), - infoAndTrace: l.infoAndTrace.WithPrefix(keyvals...), + outputLogger: l.outputLogger, + infoContext: kitlog.WithPrefix(l.infoContext, keyvals...), + traceContext: kitlog.WithPrefix(l.traceContext, keyvals...), } } func (l *infoTraceLogger) Info(keyvals ...interface{}) error { - // We log Info to the info only - l.infoOnly.Log(keyvals...) - // And pass to infoAndTrace - l.infoAndTrace.Log(keyvals...) - return nil + return l.infoContext.Log(keyvals...) } func (l *infoTraceLogger) Trace(keyvals ...interface{}) error { - l.infoAndTrace.Log(keyvals...) - return nil + return l.traceContext.Log(keyvals...) } -func (l *infoTraceLogger) SwapInfoOnlyOutput(infoLogger kitlog.Logger) { - l.infoOnlyOutputLogger.Swap(infoLogger) -} - -func (l *infoTraceLogger) SwapInfoAndTraceOutput(infoTraceLogger kitlog.Logger) { - l.infoAndTraceOutputLogger.Swap(infoTraceLogger) +func (l *infoTraceLogger) SwapOutput(infoLogger kitlog.Logger) { + l.outputLogger.Swap(infoLogger) } // If logged to as a plain kitlog logger presume the message is for Trace @@ -98,13 +89,11 @@ func (l *infoTraceLogger) SwapInfoAndTraceOutput(infoTraceLogger kitlog.Logger) // dependencies as less interesting than logs generated by us or specifically // routed by us. func (l *infoTraceLogger) Log(keyvals ...interface{}) error { - l.Trace(keyvals...) - return nil + return l.Trace(keyvals...) } // Wrap the output loggers with a a set of standard transforms, a non-blocking // ChannelLogger and an outer context -func wrapOutputLogger(outputLogger kitlog.Logger) *kitlog.Context { - return kitlog.NewContext(NonBlockingLogger(BurrowFormatLogger( - VectorValuedLogger(outputLogger)))) +func wrapOutputLogger(outputLogger kitlog.Logger) kitlog.Logger { + return NonBlockingLogger(BurrowFormatLogger(VectorValuedLogger(outputLogger))) } diff --git a/logging/loggers/info_trace_logger_test.go b/logging/loggers/info_trace_logger_test.go index 203ef65e..7db1c0e1 100644 --- a/logging/loggers/info_trace_logger_test.go +++ b/logging/loggers/info_trace_logger_test.go @@ -23,7 +23,7 @@ import ( func TestLogger(t *testing.T) { stderrLogger := kitlog.NewLogfmtLogger(os.Stderr) - logger := NewInfoTraceLogger(stderrLogger, stderrLogger) + logger := NewInfoTraceLogger(stderrLogger) logger.Trace("hello", "barry") } diff --git a/logging/types/info_trace_logger.go b/logging/types/info_trace_logger.go index 68e76eb5..63ac057b 100644 --- a/logging/types/info_trace_logger.go +++ b/logging/types/info_trace_logger.go @@ -10,13 +10,11 @@ const ( TraceLevelName = TraceChannelName ) -// InfoTraceLogger maintains two independent concurrently-safe channels of -// logging. The idea behind the independence is that you can ignore one channel -// with no performance penalty. For more fine grained filtering or aggregation -// the Info and Trace loggers can be decorated loggers that perform arbitrary -// filtering/routing/aggregation on log messages. +// InfoTraceLogger maintains provides two logging 'channels' that are interlaced +// to provide a coarse grained filter to distinguish human-consumable 'Info' +// messages and execution level 'Trace' messages. type InfoTraceLogger interface { - // Send a log message to the default channel + // Send a log message to the default channel of the implementation kitlog.Logger // Send an log message to the Info channel, formed of a sequence of key value @@ -24,8 +22,7 @@ type InfoTraceLogger interface { // monitoring the logs. But not necessarily a human who is trying to // understand or debug the system. Any handled errors or warnings should be // sent to the Info channel (where you may wish to tag them with a suitable - // key-value pair to categorise them as such). Info messages will be sent to - // the infoOnly and the infoAndTrace output loggers. + // key-value pair to categorise them as such). Info(keyvals ...interface{}) error // Send an log message to the Trace channel, formed of a sequence of key-value @@ -33,7 +30,7 @@ type InfoTraceLogger interface { // may be of interest to a machine consumer or a human who is trying to debug // the system or trying to understand the system in detail. If the messages // are very point-like and contain little structure, consider using a metric - // instead. Trace messages will only be sent to the infoAndTrace output logger. + // instead. Trace(keyvals ...interface{}) error // A logging context (see go-kit log's Context). Takes a sequence key values @@ -53,13 +50,9 @@ type InfoTraceLogger interface { // contextual values WithPrefix(keyvals ...interface{}) InfoTraceLogger - // Hot swap the underlying infoOnlyLogger with another one to re-route messages - // on the Info channel - SwapInfoOnlyOutput(infoOnlyLogger kitlog.Logger) + // Hot swap the underlying outputLogger with another one to re-route messages + SwapOutput(outputLogger kitlog.Logger) - // Hot swap the underlying infoAndTraceLogger with another one to re-route messages - // on the Info and Trace channels - SwapInfoAndTraceOutput(infoTraceLogger kitlog.Logger) } // Interface assertions -- GitLab