From 9493fe0bb20661d3d94bc9c44f79d6a327f31d36 Mon Sep 17 00:00:00 2001 From: Simon Richardson Date: Mon, 6 May 2024 17:26:56 +0100 Subject: [PATCH 1/4] Apply the logger config by label In order to support labels from Juju, we would like to be able to configure loggers by their labels. So if a logger has a label of a model namespace (UUID) then searching from the root module to set the level of a module should be possible. As you can configure both module names and labels at the same time, this becomes tricky. We don't want users to be able to configure a logger via a label directly and the label should always take precedence over a user input. --- context.go | 27 ++++++++ logger_test.go | 180 +++++++++++++++++++++++++++++++++++++++++++++++++ module.go | 12 ++++ 3 files changed, 219 insertions(+) diff --git a/context.go b/context.go index 4cf9ce7..fb62de1 100644 --- a/context.go +++ b/context.go @@ -318,3 +318,30 @@ func (c *Context) ConfigureLoggers(specification string) error { c.ApplyConfig(config) return nil } + +// ApplyLoggerLevelByLabels sets the level of all loggers that have the +// specified labels to the given level. +func (c *Context) ApplyLoggerLevelByLabels(labels Labels, level Level) { + config := c.GetConfigByLabels(labels, level) + c.ApplyConfig(config) +} + +// GetConfigByLabels locates all the modules that have the specified labels. +// Returns the config if the module has the given labels, which +// may be a subset of the logger labels. The label key and values must match +// and it must match all of the labels in the argument. +func (c *Context) GetConfigByLabels(labels Labels, level Level) Config { + c.modulesMutex.Lock() + defer c.modulesMutex.Unlock() + + config := make(Config) + for name, module := range c.modules { + if !module.hasLabelIntersection(labels) { + continue + } + + config[name] = level + } + + return config +} diff --git a/logger_test.go b/logger_test.go index fd0bc19..8c3e0cc 100644 --- a/logger_test.go +++ b/logger_test.go @@ -161,6 +161,186 @@ func (s *LoggerSuite) TestInheritedLabels(c *gc.C) { }) } +func (s *LoggerSuite) TestInheritedLabelsResetLabels(c *gc.C) { + writer := &loggo.TestWriter{} + context := loggo.NewContext(loggo.INFO) + err := context.AddWriter("test", writer) + c.Assert(err, gc.IsNil) + + logger := context.GetLogger("testing") + + nestedLoggerWithLabels := logger. + ChildWithLabels("nested", loggo.Labels{"foo": "bar"}) + deepNestedLoggerWithLabels := nestedLoggerWithLabels. + ChildWithLabels("nested", loggo.Labels{"foo": "bar"}). + ChildWithLabels("deepnested", loggo.Labels{"fred": "tim"}) + + // Ensure we can set the logger level to error. + + deepNestedLoggerWithLabels.SetLogLevel(loggo.ERROR) + c.Check(deepNestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.ERROR) + c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.ERROR) + + logger.Logf(loggo.INFO, "without labels") + nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") + deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") + + logs := writer.Log() + c.Assert(logs, gc.HasLen, 2, gc.Commentf("len = %d", len(logs))) + c.Check(logs[0].Message, gc.Equals, "without labels") + c.Check(logs[0].Labels, gc.HasLen, 0) + + c.Check(logs[1].Message, gc.Equals, "with nested labels") + c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{"foo": "bar"}) + + writer.Clear() + + // Ensure that we can reset the logger levels. + + context.ResetLoggerLevels() + + c.Check(deepNestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.WARNING) + c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.UNSPECIFIED) + + logger.Logf(loggo.INFO, "without labels") + nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") + deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") + + logs = writer.Log() + c.Assert(logs, gc.HasLen, 0, gc.Commentf("len = %d", len(logs))) + + writer.Clear() + + // Ensure that we can configure the logger levels again. + + context.ResetLoggerLevels() + context.ConfigureLoggers("testing.nested.nested.deepnested=INFO") + + c.Check(deepNestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.INFO) + c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.INFO) + + logger.Logf(loggo.INFO, "without labels") + nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") + deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") + + logs = writer.Log() + c.Assert(logs, gc.HasLen, 1, gc.Commentf("len = %d", len(logs))) + + c.Check(logs[0].Message, gc.Equals, "with deep nested labels") + c.Check(logs[0].Labels, gc.DeepEquals, loggo.Labels{ + "foo": "bar", + "fred": "tim", + }) +} + +func (s *LoggerSuite) TestInheritedLabelsConfigByLabels(c *gc.C) { + writer := &loggo.TestWriter{} + context := loggo.NewContext(loggo.INFO) + err := context.AddWriter("test", writer) + c.Assert(err, gc.IsNil) + + logger := context.GetLogger("testing") + + nestedLoggerWithLabels := logger. + ChildWithLabels("nested", loggo.Labels{"foo": "bar"}) + deepNestedLoggerWithLabels := nestedLoggerWithLabels. + ChildWithLabels("nested", loggo.Labels{"foo": "bar"}). + ChildWithLabels("deepnested", loggo.Labels{"fred": "tim"}) + + // Apply the ERROR level to the logger with the labels "foo=bar". + + context.ResetLoggerLevels() + logger.SetLogLevel(loggo.INFO) + context.ApplyLoggerLevelByLabels(loggo.Labels{"foo": "bar"}, loggo.ERROR) + + c.Check(nestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.ERROR) + c.Check(nestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.ERROR) + + c.Check(deepNestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.ERROR) + c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.ERROR) + + // Apply the INFO level to the logger with the labels "foo=bar" and + // "fred=tim". + + context.ApplyLoggerLevelByLabels(loggo.Labels{ + "foo": "bar", + "fred": "tim", + }, loggo.INFO) + + c.Check(nestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.ERROR) + c.Check(nestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.ERROR) + + c.Check(deepNestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.INFO) + c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.INFO) + + logger.Logf(loggo.INFO, "without labels") + nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") + deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") + + logs := writer.Log() + c.Assert(logs, gc.HasLen, 2, gc.Commentf("len = %d", len(logs))) + c.Check(logs[0].Message, gc.Equals, "without labels") + c.Check(logs[0].Labels, gc.HasLen, 0) + + c.Check(logs[1].Message, gc.Equals, "with deep nested labels") + c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ + "foo": "bar", + "fred": "tim", + }) + + writer.Clear() + + // Apply the INFO level to the logger with the labels "hello=world". + // Nothing matches this, so it should have no effect. + + context.ApplyLoggerLevelByLabels(loggo.Labels{ + "hello": "world", + }, loggo.INFO) + + logger.Logf(loggo.INFO, "without labels") + nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") + deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") + + logs = writer.Log() + c.Assert(logs, gc.HasLen, 2, gc.Commentf("len = %d", len(logs))) + c.Check(logs[0].Message, gc.Equals, "without labels") + c.Check(logs[0].Labels, gc.HasLen, 0) + + c.Check(logs[1].Message, gc.Equals, "with deep nested labels") + c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ + "foo": "bar", + "fred": "tim", + }) + + writer.Clear() + + // Apply the INFO level to the logger with the labels "foo=bar", + // "fred=tim" and "hello=world". + // This should not match anything and have no effect, as we expect + // to match ALL the labels. + + context.ApplyLoggerLevelByLabels(loggo.Labels{ + "foo": "bar", + "fred": "tim", + "hello": "world", + }, loggo.ERROR) + + logger.Logf(loggo.INFO, "without labels") + nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") + deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") + + logs = writer.Log() + c.Assert(logs, gc.HasLen, 2, gc.Commentf("len = %d", len(logs))) + c.Check(logs[0].Message, gc.Equals, "without labels") + c.Check(logs[0].Labels, gc.HasLen, 0) + + c.Check(logs[1].Message, gc.Equals, "with deep nested labels") + c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ + "foo": "bar", + "fred": "tim", + }) +} + func (s *LoggerSuite) TestLogWithStaticAndDynamicLabels(c *gc.C) { writer := &loggo.TestWriter{} context := loggo.NewContext(loggo.INFO) diff --git a/module.go b/module.go index 6d98393..2ba3883 100644 --- a/module.go +++ b/module.go @@ -61,3 +61,15 @@ func (m *module) write(entry Entry) { entry.Module = m.name m.context.write(entry) } + +// hasLabelIntersection returns true if the module has the given labels, which +// may be a subset of the module's labels. The label key and values must match +// and it must match all of the labels in the argument. +func (m *module) hasLabelIntersection(labels Labels) bool { + for labelKey, labelValue := range labels { + if moduleValue, ok := m.labels[labelKey]; !ok || moduleValue != labelValue { + return false + } + } + return true +} From d8c41f11ce55246f5619e38310b2633b81b2783f Mon Sep 17 00:00:00 2001 From: Simon Richardson Date: Mon, 6 May 2024 17:33:01 +0100 Subject: [PATCH 2/4] Remove the logger label concept Labels should not be applied to loggers. There is no way to reference them directly from a root module. Labels for this concept should be more like Attributes, something that can be dynamic for a given logger, although I suspect that they should just be sent via the Logf method. --- logger.go | 31 +-------- logger_test.go | 169 ------------------------------------------------- 2 files changed, 1 insertion(+), 199 deletions(-) diff --git a/logger.go b/logger.go index 09fa9d2..ec43dae 100644 --- a/logger.go +++ b/logger.go @@ -24,31 +24,11 @@ const ( // The zero Logger value is usable - any messages logged // to it will be sent to the root Logger. type Logger struct { - impl *module - labels Labels + impl *module - // CallDepth is the number of stack frames to ascend to find the caller. callDepth int } -// WithLabels returns a logger whose module is the same as this logger and -// the returned logger will add the specified labels to each log entry. -// WithLabels only target a specific logger with labels. Children of the logger -// will not inherit the labels. -// To add labels to all child loggers, use ChildWithLabels. -func (logger Logger) WithLabels(labels Labels) Logger { - if len(labels) == 0 { - return logger - } - - result := logger - result.labels = make(Labels) - for k, v := range labels { - result.labels[k] = v - } - return result -} - // WithCallDepth returns a logger whose call depth is set to the specified // value. func (logger Logger) WithCallDepth(callDepth int) Logger { @@ -244,9 +224,6 @@ func (logger Logger) logCallf(calldepth int, level Level, message string, extraL for k, v := range module.labels { entry.Labels[k] = v } - for k, v := range logger.labels { - entry.Labels[k] = v - } // Add extra labels if there's any given. for k, v := range extraLabels { entry.Labels[k] = v @@ -274,12 +251,6 @@ func (logger Logger) Infof(message string, args ...interface{}) { logger.Logf(INFO, message, args...) } -// InfoWithLabelsf logs the printf-formatted message at info level with extra -// labels. -func (logger Logger) InfoWithLabelsf(message string, extraLabels map[string]string, args ...interface{}) { - logger.LogWithLabelsf(INFO, message, extraLabels, args...) -} - // Debugf logs the printf-formatted message at debug level. func (logger Logger) Debugf(message string, args ...interface{}) { logger.Logf(DEBUG, message, args...) diff --git a/logger_test.go b/logger_test.go index 8c3e0cc..8b0566e 100644 --- a/logger_test.go +++ b/logger_test.go @@ -28,95 +28,6 @@ func (s *LoggerSuite) TestRootLogger(c *gc.C) { c.Check(root.IsTraceEnabled(), gc.Equals, false) } -func (s *LoggerSuite) TestWithLabels(c *gc.C) { - writer := &loggo.TestWriter{} - context := loggo.NewContext(loggo.INFO) - err := context.AddWriter("test", writer) - c.Assert(err, gc.IsNil) - - logger := context.GetLogger("testing") - loggerWithLabels := logger.WithLabels(loggo.Labels{"foo": "bar"}) - loggerWithTagsAndLabels := logger. - ChildWithTags("withTags", "tag1", "tag2"). - WithLabels(loggo.Labels{"hello": "world"}) - - logger.Logf(loggo.INFO, "without labels") - loggerWithLabels.Logf(loggo.INFO, "with labels") - loggerWithTagsAndLabels.Logf(loggo.INFO, "with tags and labels") - - logs := writer.Log() - c.Assert(logs, gc.HasLen, 3) - c.Check(logs[0].Message, gc.Equals, "without labels") - c.Check(logs[0].Labels, gc.HasLen, 0) - c.Check(logs[1].Message, gc.Equals, "with labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{"foo": "bar"}) - c.Check(logs[2].Message, gc.Equals, "with tags and labels") - c.Check(logs[2].Labels, gc.DeepEquals, loggo.Labels{ - "logger-tags": "tag1,tag2", - "hello": "world", - }) -} - -func (s *LoggerSuite) TestNonInheritedLabels(c *gc.C) { - writer := &loggo.TestWriter{} - context := loggo.NewContext(loggo.INFO) - err := context.AddWriter("test", writer) - c.Assert(err, gc.IsNil) - - logger := context.GetLogger("testing"). - WithLabels(loggo.Labels{"hello": "world"}) - - inheritedLoggerWithLabels := logger. - ChildWithLabels("inherited", loggo.Labels{"foo": "bar"}) - - logger.Logf(loggo.INFO, "with labels") - inheritedLoggerWithLabels.Logf(loggo.INFO, "with inherited labels") - - logs := writer.Log() - c.Assert(logs, gc.HasLen, 2) - - // The second log message should _only_ have the inherited labels. - - c.Check(logs[0].Message, gc.Equals, "with labels") - c.Check(logs[0].Labels, gc.DeepEquals, loggo.Labels{"hello": "world"}) - - c.Check(logs[1].Message, gc.Equals, "with inherited labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{"foo": "bar"}) -} - -func (s *LoggerSuite) TestNonInheritedWithInheritedLabels(c *gc.C) { - writer := &loggo.TestWriter{} - context := loggo.NewContext(loggo.INFO) - err := context.AddWriter("test", writer) - c.Assert(err, gc.IsNil) - - logger := context.GetLogger("testing") - - inheritedLoggerWithLabels := logger. - ChildWithLabels("inherited", loggo.Labels{"foo": "bar"}) - - scopedLoggerWithLabels := inheritedLoggerWithLabels. - WithLabels(loggo.Labels{"hello": "world"}) - - inheritedLoggerWithLabels.Logf(loggo.INFO, "with inherited labels") - scopedLoggerWithLabels.Logf(loggo.INFO, "with scoped labels") - - logs := writer.Log() - c.Assert(logs, gc.HasLen, 2) - - // The second log message should have both the inherited labels and - // scoped labels. - - c.Check(logs[0].Message, gc.Equals, "with inherited labels") - c.Check(logs[0].Labels, gc.DeepEquals, loggo.Labels{"foo": "bar"}) - - c.Check(logs[1].Message, gc.Equals, "with scoped labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ - "foo": "bar", - "hello": "world", - }) -} - func (s *LoggerSuite) TestInheritedLabels(c *gc.C) { writer := &loggo.TestWriter{} context := loggo.NewContext(loggo.INFO) @@ -341,86 +252,6 @@ func (s *LoggerSuite) TestInheritedLabelsConfigByLabels(c *gc.C) { }) } -func (s *LoggerSuite) TestLogWithStaticAndDynamicLabels(c *gc.C) { - writer := &loggo.TestWriter{} - context := loggo.NewContext(loggo.INFO) - err := context.AddWriter("test", writer) - c.Assert(err, gc.IsNil) - - logger := context.GetLogger("testing") - loggerWithLabels := logger.WithLabels(loggo.Labels{"foo": "bar"}) - - loggerWithLabels.LogWithLabelsf(loggo.INFO, "no extra labels", nil) - loggerWithLabels.LogWithLabelsf(loggo.INFO, "with extra labels", map[string]string{ - "domain": "status", - "kind": "machine", - "id": "0", - "value": "idle", - }) - - logs := writer.Log() - c.Assert(logs, gc.HasLen, 2) - c.Check(logs[0].Message, gc.Equals, "no extra labels") - c.Check(logs[0].Labels, gc.DeepEquals, loggo.Labels{"foo": "bar"}) - c.Check(logs[1].Message, gc.Equals, "with extra labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ - "foo": "bar", "domain": "status", "id": "0", "kind": "machine", "value": "idle"}) -} - -func (s *LoggerSuite) TestLogWithExtraLabels(c *gc.C) { - writer := &loggo.TestWriter{} - context := loggo.NewContext(loggo.INFO) - err := context.AddWriter("test", writer) - c.Assert(err, gc.IsNil) - - logger := context.GetLogger("testing") - - logger.LogWithLabelsf(loggo.INFO, "no extra labels", nil) - logger.LogWithLabelsf(loggo.INFO, "with extra labels", map[string]string{ - "domain": "status", - "kind": "machine", - "id": "0", - "value": "idle", - }) - - logs := writer.Log() - c.Assert(logs, gc.HasLen, 2) - c.Check(logs[0].Message, gc.Equals, "no extra labels") - c.Check(logs[0].Labels, gc.HasLen, 0) - c.Check(logs[1].Message, gc.Equals, "with extra labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ - "domain": "status", "id": "0", "kind": "machine", "value": "idle"}) -} - -func (s *LoggerSuite) TestInfoWithLabelsf(c *gc.C) { - writer := &loggo.TestWriter{} - context := loggo.NewContext(loggo.INFO) - err := context.AddWriter("test", writer) - c.Assert(err, gc.IsNil) - - logger := context.GetLogger("testing") - logger.SetLogLevel(loggo.INFO) - c.Assert(logger.LogLevel(), gc.Equals, loggo.INFO) - - logger.InfoWithLabelsf("no extra labels", nil) - logger.InfoWithLabelsf("with extra labels", map[string]string{ - "domain": "status", - "kind": "machine", - "id": "0", - "value": "idle", - }) - - logs := writer.Log() - c.Assert(logs, gc.HasLen, 2) - c.Check(logs[0].Message, gc.Equals, "no extra labels") - c.Check(logs[0].Labels, gc.HasLen, 0) - c.Check(logs[0].Level, gc.Equals, loggo.INFO) - c.Check(logs[1].Message, gc.Equals, "with extra labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ - "domain": "status", "id": "0", "kind": "machine", "value": "idle"}) - c.Check(logs[1].Level, gc.Equals, loggo.INFO) -} - func (s *LoggerSuite) TestSetLevel(c *gc.C) { logger := loggo.GetLogger("testing") From 564b008cb107ae501ddfcbe4e38a7c5173e475ad Mon Sep 17 00:00:00 2001 From: Simon Richardson Date: Mon, 6 May 2024 22:32:23 +0100 Subject: [PATCH 3/4] Remove the custom functions and use existing methods It's much cleaner if we can reuse existing methods to provide the additional functionality. The labels provide addition matching capabilities to config loggers and will only config the loggers that have a label intersection. --- context.go | 64 +++++++++++++--------------- labels.go | 12 ++++++ logger_test.go | 112 +++++++++++++++++++++++++++++++++---------------- 3 files changed, 115 insertions(+), 73 deletions(-) diff --git a/context.go b/context.go index fb62de1..78a8c7a 100644 --- a/context.go +++ b/context.go @@ -136,14 +136,14 @@ func (c *Context) getLoggerModule(name string, tags []string) *module { } // getLoggerModulesByTag returns modules that have the associated tag. -func (c *Context) getLoggerModulesByTag(label string) []*module { +func (c *Context) getLoggerModulesByTag(tag string) []*module { var modules []*module for _, mod := range c.modules { if len(mod.tags) == 0 { continue } - if _, ok := mod.tagsLookup[label]; ok { + if _, ok := mod.tagsLookup[tag]; ok { modules = append(modules, mod) } } @@ -179,15 +179,22 @@ func (c *Context) CompleteConfig() Config { } // ApplyConfig configures the logging modules according to the provided config. -func (c *Context) ApplyConfig(config Config) { +func (c *Context) ApplyConfig(config Config, labels ...Labels) { + label := mergeLabels(labels) + c.modulesMutex.Lock() defer c.modulesMutex.Unlock() + for name, level := range config { tag := extractConfigTag(name) if tag == "" { module := c.getLoggerModule(name, nil) + + // If the module doesn't have the label, then we skip it. + if !module.hasLabelIntersection(label) { + continue + } module.setLevel(level) - continue } // Ensure that we save the config for lazy loggers to pick up correctly. @@ -196,6 +203,11 @@ func (c *Context) ApplyConfig(config Config) { // Config contains a named tag, use that for selecting the loggers. modules := c.getLoggerModulesByTag(tag) for _, module := range modules { + // If the module doesn't have the label, then we skip it. + if !module.hasLabelIntersection(label) { + continue + } + module.setLevel(level) } } @@ -302,46 +314,26 @@ func (c *Context) ResetWriters() { // ConfigureLoggers configures loggers according to the given string // specification, which specifies a set of modules and their associated -// logging levels. Loggers are colon- or semicolon-separated; each +// logging levels. Loggers are colon- or semicolon-separated; each // module is specified as =. White space outside of -// module names and levels is ignored. The root module is specified +// module names and levels is ignored. The root module is specified // with the name "". // // An example specification: // -// `=ERROR; foo.bar=WARNING` -func (c *Context) ConfigureLoggers(specification string) error { +// =ERROR; foo.bar=WARNING +// +// Label matching can be applied to the loggers by providing a set of labels +// to the function. If a logger has a label that matches the provided labels, +// then the logger will be configured with the provided level. If the logger +// does not have a label that matches the provided labels, then the logger +// will not be configured. No labels will configure all loggers in the +// specification. +func (c *Context) ConfigureLoggers(specification string, labels ...Labels) error { config, err := ParseConfigString(specification) if err != nil { return err } - c.ApplyConfig(config) + c.ApplyConfig(config, labels...) return nil } - -// ApplyLoggerLevelByLabels sets the level of all loggers that have the -// specified labels to the given level. -func (c *Context) ApplyLoggerLevelByLabels(labels Labels, level Level) { - config := c.GetConfigByLabels(labels, level) - c.ApplyConfig(config) -} - -// GetConfigByLabels locates all the modules that have the specified labels. -// Returns the config if the module has the given labels, which -// may be a subset of the logger labels. The label key and values must match -// and it must match all of the labels in the argument. -func (c *Context) GetConfigByLabels(labels Labels, level Level) Config { - c.modulesMutex.Lock() - defer c.modulesMutex.Unlock() - - config := make(Config) - for name, module := range c.modules { - if !module.hasLabelIntersection(labels) { - continue - } - - config[name] = level - } - - return config -} diff --git a/labels.go b/labels.go index 3d58c9a..41ba70c 100644 --- a/labels.go +++ b/labels.go @@ -11,3 +11,15 @@ const ( // Labels represents key values which are assigned to a log entry. type Labels map[string]string + +// mergeLabels merges multiple sets of labels into a single set. +// Later sets of labels take precedence over earlier sets. +func mergeLabels(labels []Labels) Labels { + result := make(Labels) + for _, l := range labels { + for k, v := range l { + result[k] = v + } + } + return result +} diff --git a/logger_test.go b/logger_test.go index 8b0566e..a5d9494 100644 --- a/logger_test.go +++ b/logger_test.go @@ -161,92 +161,130 @@ func (s *LoggerSuite) TestInheritedLabelsConfigByLabels(c *gc.C) { // Apply the ERROR level to the logger with the labels "foo=bar". context.ResetLoggerLevels() - logger.SetLogLevel(loggo.INFO) - context.ApplyLoggerLevelByLabels(loggo.Labels{"foo": "bar"}, loggo.ERROR) + context.ConfigureLoggers("testing=INFO") + context.ConfigureLoggers("testing.nested=ERROR", loggo.Labels{"foo": "bar"}) c.Check(nestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.ERROR) c.Check(nestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.ERROR) c.Check(deepNestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.ERROR) - c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.ERROR) - - // Apply the INFO level to the logger with the labels "foo=bar" and - // "fred=tim". - - context.ApplyLoggerLevelByLabels(loggo.Labels{ - "foo": "bar", - "fred": "tim", - }, loggo.INFO) - - c.Check(nestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.ERROR) - c.Check(nestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.ERROR) - - c.Check(deepNestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.INFO) - c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.INFO) + c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.UNSPECIFIED) logger.Logf(loggo.INFO, "without labels") nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") logs := writer.Log() - c.Assert(logs, gc.HasLen, 2, gc.Commentf("len = %d", len(logs))) + c.Assert(logs, gc.HasLen, 1, gc.Commentf("len = %d", len(logs))) + c.Check(logs[0].Message, gc.Equals, "without labels") c.Check(logs[0].Labels, gc.HasLen, 0) - c.Check(logs[1].Message, gc.Equals, "with deep nested labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ - "foo": "bar", - "fred": "tim", - }) - writer.Clear() - // Apply the INFO level to the logger with the labels "hello=world". + // Apply the INFO level to the logger with the labels "foo=bar" and + // "fred=tim". + + run := func(labels ...loggo.Labels) { + context.ConfigureLoggers("testing.nested.nested.deepnested=INFO", labels...) + + c.Check(nestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.ERROR) + c.Check(nestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.ERROR) + + c.Check(deepNestedLoggerWithLabels.EffectiveLogLevel(), gc.Equals, loggo.INFO) + c.Check(deepNestedLoggerWithLabels.LogLevel(), gc.Equals, loggo.INFO) + + logger.Logf(loggo.INFO, "without labels") + nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") + deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") + + logs = writer.Log() + c.Assert(logs, gc.HasLen, 2, gc.Commentf("len = %d", len(logs))) + c.Check(logs[0].Message, gc.Equals, "without labels") + c.Check(logs[0].Labels, gc.HasLen, 0) + + c.Check(logs[1].Message, gc.Equals, "with deep nested labels") + c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ + "foo": "bar", + "fred": "tim", + }) + + writer.Clear() + } + + // Notice that the order of the labels are merged and last label wins. + + run(loggo.Labels{"foo": "bar", "fred": "tim"}) + run(loggo.Labels{"foo": "bar"}, loggo.Labels{"fred": "tim"}) + run(loggo.Labels{"foo": "bar", "fred": "john"}, loggo.Labels{"fred": "tim"}) +} + +func (s *LoggerSuite) TestInheritedLabelsConfigByLabelsIgnoresInvalidLabels(c *gc.C) { + writer := &loggo.TestWriter{} + context := loggo.NewContext(loggo.INFO) + err := context.AddWriter("test", writer) + c.Assert(err, gc.IsNil) + + logger := context.GetLogger("testing") + + nestedLoggerWithLabels := logger. + ChildWithLabels("nested", loggo.Labels{"foo": "bar"}) + deepNestedLoggerWithLabels := nestedLoggerWithLabels. + ChildWithLabels("nested", loggo.Labels{"foo": "bar"}). + ChildWithLabels("deepnested", loggo.Labels{"fred": "tim"}) + + // Apply the ERROR level to the logger with the labels "hello=world". // Nothing matches this, so it should have no effect. - context.ApplyLoggerLevelByLabels(loggo.Labels{ + context.ConfigureLoggers("testing.nested.nested.deepnested=ERROR", loggo.Labels{ "hello": "world", - }, loggo.INFO) + }) logger.Logf(loggo.INFO, "without labels") nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") - logs = writer.Log() - c.Assert(logs, gc.HasLen, 2, gc.Commentf("len = %d", len(logs))) + logs := writer.Log() + c.Assert(logs, gc.HasLen, 3, gc.Commentf("len = %d", len(logs))) c.Check(logs[0].Message, gc.Equals, "without labels") c.Check(logs[0].Labels, gc.HasLen, 0) - c.Check(logs[1].Message, gc.Equals, "with deep nested labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ + c.Check(logs[1].Message, gc.Equals, "with nested labels") + c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{"foo": "bar"}) + + c.Check(logs[2].Message, gc.Equals, "with deep nested labels") + c.Check(logs[2].Labels, gc.DeepEquals, loggo.Labels{ "foo": "bar", "fred": "tim", }) writer.Clear() - // Apply the INFO level to the logger with the labels "foo=bar", + // Apply the ERROR level to the logger with the labels "foo=bar", // "fred=tim" and "hello=world". // This should not match anything and have no effect, as we expect // to match ALL the labels. - context.ApplyLoggerLevelByLabels(loggo.Labels{ + context.ConfigureLoggers("testing.nested.nested.deepnested=ERROR", loggo.Labels{ "foo": "bar", "fred": "tim", "hello": "world", - }, loggo.ERROR) + }) logger.Logf(loggo.INFO, "without labels") nestedLoggerWithLabels.Logf(loggo.INFO, "with nested labels") deepNestedLoggerWithLabels.Logf(loggo.INFO, "with deep nested labels") logs = writer.Log() - c.Assert(logs, gc.HasLen, 2, gc.Commentf("len = %d", len(logs))) + c.Assert(logs, gc.HasLen, 3, gc.Commentf("len = %d", len(logs))) c.Check(logs[0].Message, gc.Equals, "without labels") c.Check(logs[0].Labels, gc.HasLen, 0) - c.Check(logs[1].Message, gc.Equals, "with deep nested labels") - c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{ + c.Check(logs[1].Message, gc.Equals, "with nested labels") + c.Check(logs[1].Labels, gc.DeepEquals, loggo.Labels{"foo": "bar"}) + + c.Check(logs[2].Message, gc.Equals, "with deep nested labels") + c.Check(logs[2].Labels, gc.DeepEquals, loggo.Labels{ "foo": "bar", "fred": "tim", }) From 48b0873a0269d5f3021dab9deb0a432e8db03d34 Mon Sep 17 00:00:00 2001 From: Simon Richardson Date: Tue, 7 May 2024 15:46:21 +0100 Subject: [PATCH 4/4] Use lables when resetting logger levels Take into consideration the labels when resetting the logger levels. We don't want to reset all the logger levels if we're using a singular global logger. --- context.go | 21 +++++++---- context_test.go | 94 ++++++++++++++++++++++++++++++++++++++++++++++--- logger.go | 22 ++++-------- logger_test.go | 23 ++++++++++++ 4 files changed, 134 insertions(+), 26 deletions(-) diff --git a/context.go b/context.go index 78a8c7a..fc3d0dd 100644 --- a/context.go +++ b/context.go @@ -74,12 +74,12 @@ func (c *Context) GetAllLoggerTags() []string { names[k] = v } } - labels := make([]string, 0, len(names)) + tags := make([]string, 0, len(names)) for name := range names { - labels = append(labels, name) + tags = append(tags, name) } - sort.Strings(labels) - return labels + sort.Strings(tags) + return tags } func (c *Context) getLoggerModule(name string, tags []string) *module { @@ -215,15 +215,22 @@ func (c *Context) ApplyConfig(config Config, labels ...Labels) { // ResetLoggerLevels iterates through the known logging modules and sets the // levels of all to UNSPECIFIED, except for which is set to WARNING. -func (c *Context) ResetLoggerLevels() { +// If labels are provided, then only loggers that have the provided labels +// will be reset. +func (c *Context) ResetLoggerLevels(labels ...Labels) { + label := mergeLabels(labels) + c.modulesMutex.Lock() defer c.modulesMutex.Unlock() + // Setting the root module to UNSPECIFIED will set it to WARNING. for _, module := range c.modules { + if !module.hasLabelIntersection(label) { + continue + } + module.setLevel(UNSPECIFIED) } - // We can safely just wipe everything here. - c.modulesTagConfig = make(map[string]Level) } func (c *Context) write(entry Entry) { diff --git a/context_test.go b/context_test.go index 01588bc..2f55900 100644 --- a/context_test.go +++ b/context_test.go @@ -261,7 +261,7 @@ func (*ContextSuite) TestApplyConfigTags(c *gc.C) { }) } -func (*ContextSuite) TestApplyConfigLabelsAppliesToNewLoggers(c *gc.C) { +func (*ContextSuite) TestApplyConfigTagsAppliesToNewLoggers(c *gc.C) { context := loggo.NewContext(loggo.WARNING) context.ApplyConfig(loggo.Config{"#one": loggo.TRACE}) @@ -289,7 +289,7 @@ func (*ContextSuite) TestApplyConfigLabelsAppliesToNewLoggers(c *gc.C) { }) } -func (*ContextSuite) TestApplyConfigLabelsAppliesToNewLoggersWithMultipleTags(c *gc.C) { +func (*ContextSuite) TestApplyConfigTagsAppliesToNewLoggersWithMultipleTags(c *gc.C) { context := loggo.NewContext(loggo.WARNING) // Invert the order here, to ensure that the config order doesn't matter, @@ -312,7 +312,7 @@ func (*ContextSuite) TestApplyConfigLabelsAppliesToNewLoggersWithMultipleTags(c }) } -func (*ContextSuite) TestApplyConfigLabelsResetLoggerLevels(c *gc.C) { +func (*ContextSuite) TestApplyConfigTagsResetLoggerLevels(c *gc.C) { context := loggo.NewContext(loggo.WARNING) context.ApplyConfig(loggo.Config{"#one": loggo.TRACE}) @@ -339,7 +339,93 @@ func (*ContextSuite) TestApplyConfigLabelsResetLoggerLevels(c *gc.C) { }) } -func (*ContextSuite) TestApplyConfigTagsAddative(c *gc.C) { +func (*ContextSuite) TestApplyConfigTagsResetLoggerLevelsUsingLabels(c *gc.C) { + context := loggo.NewContext(loggo.WARNING) + + context.ApplyConfig(loggo.Config{"#one": loggo.TRACE}) + context.ApplyConfig(loggo.Config{"#two": loggo.DEBUG}) + + context.GetLogger("a", "one").ChildWithLabels("b", loggo.Labels{"x": "y"}) + context.GetLogger("c.d", "one") + context.GetLogger("e", "two") + + // If a label is available on a logger, then resetting the levels should + // not remove the label. + + context.ResetLoggerLevels() + + c.Assert(context.Config(), gc.DeepEquals, + loggo.Config{ + "": loggo.WARNING, + }) + c.Assert(context.CompleteConfig(), gc.DeepEquals, + loggo.Config{ + "": loggo.WARNING, + "a": loggo.UNSPECIFIED, + "a.b": loggo.UNSPECIFIED, + "c": loggo.UNSPECIFIED, + "c.d": loggo.UNSPECIFIED, + "e": loggo.UNSPECIFIED, + }) +} + +func (*ContextSuite) TestApplyConfigTagsResetLoggerLevelsUsingLabelsRemoval(c *gc.C) { + context := loggo.NewContext(loggo.WARNING) + + context.ApplyConfig(loggo.Config{"#one": loggo.TRACE}) + context.ApplyConfig(loggo.Config{"#two": loggo.DEBUG}) + + context.GetLogger("a", "one").ChildWithLabels("b", loggo.Labels{"x": "y"}).ChildWithTags("g", "one") + context.GetLogger("c.d", "one") + context.GetLogger("e", "two") + context.GetLogger("f") + + // Ensure that the logger that matches exactly the label is removed, + // including it's children. So we observe hierarchy in the removal. + + c.Assert(context.Config(), gc.DeepEquals, + loggo.Config{ + "": loggo.WARNING, + "a": loggo.TRACE, + "a.b.g": loggo.TRACE, + "c.d": loggo.TRACE, + "e": loggo.DEBUG, + }) + c.Assert(context.CompleteConfig(), gc.DeepEquals, + loggo.Config{ + "": loggo.WARNING, + "a": loggo.TRACE, + "a.b": loggo.UNSPECIFIED, + "a.b.g": loggo.TRACE, + "c": loggo.UNSPECIFIED, + "c.d": loggo.TRACE, + "e": loggo.DEBUG, + "f": loggo.UNSPECIFIED, + }) + + context.ResetLoggerLevels(loggo.Labels{"x": "y"}) + + c.Assert(context.Config(), gc.DeepEquals, + loggo.Config{ + "": loggo.WARNING, + "a": loggo.TRACE, + "c.d": loggo.TRACE, + "e": loggo.DEBUG, + }) + c.Assert(context.CompleteConfig(), gc.DeepEquals, + loggo.Config{ + "": loggo.WARNING, + "a": loggo.TRACE, + "a.b": loggo.UNSPECIFIED, + "a.b.g": loggo.UNSPECIFIED, + "c": loggo.UNSPECIFIED, + "c.d": loggo.TRACE, + "e": loggo.DEBUG, + "f": loggo.UNSPECIFIED, + }) +} + +func (*ContextSuite) TestApplyConfigTagsAdditive(c *gc.C) { context := loggo.NewContext(loggo.WARNING) context.ApplyConfig(loggo.Config{"#one": loggo.TRACE}) context.ApplyConfig(loggo.Config{"#two": loggo.DEBUG}) diff --git a/logger.go b/logger.go index ec43dae..9706a29 100644 --- a/logger.go +++ b/logger.go @@ -131,6 +131,11 @@ func (logger Logger) Tags() []string { return logger.getModule().tags } +// Labels returns the configured labels of the logger's module. +func (logger Logger) Labels() Labels { + return logger.getModule().labels +} + // EffectiveLogLevel returns the effective min log level of // the receiver - that is, messages with a lesser severity // level will be discarded. @@ -159,15 +164,6 @@ func (logger Logger) Logf(level Level, message string, args ...interface{}) { logger.LogCallf(logger.callDepth, level, message, args...) } -// LogWithlabelsf logs a printf-formatted message at the given level with extra -// labels. The given labels will be added to the log entry. -// A message will be discarded if level is less than the the effective log level -// of the logger. Note that the writers may also filter out messages that are -// less than their registered minimum severity level. -func (logger Logger) LogWithLabelsf(level Level, message string, extraLabels map[string]string, args ...interface{}) { - logger.logCallf(logger.callDepth, level, message, extraLabels, args...) -} - // LogCallf logs a printf-formatted message at the given level. // The location of the call is indicated by the calldepth argument. // A calldepth of 1 means the function that called this function. @@ -176,12 +172,12 @@ func (logger Logger) LogWithLabelsf(level Level, message string, extraLabels map // Note that the writers may also filter out messages that // are less than their registered minimum severity level. func (logger Logger) LogCallf(calldepth int, level Level, message string, args ...interface{}) { - logger.logCallf(calldepth+1, level, message, nil, args...) + logger.logCallf(calldepth+1, level, message, args...) } // logCallf is a private method for logging a printf-formatted message at the // given level. Used by LogWithLabelsf and LogCallf. -func (logger Logger) logCallf(calldepth int, level Level, message string, extraLabels map[string]string, args ...interface{}) { +func (logger Logger) logCallf(calldepth int, level Level, message string, args ...interface{}) { module := logger.getModule() if !module.willWrite(level) { return @@ -224,10 +220,6 @@ func (logger Logger) logCallf(calldepth int, level Level, message string, extraL for k, v := range module.labels { entry.Labels[k] = v } - // Add extra labels if there's any given. - for k, v := range extraLabels { - entry.Labels[k] = v - } module.write(entry) } diff --git a/logger_test.go b/logger_test.go index a5d9494..0713aab 100644 --- a/logger_test.go +++ b/logger_test.go @@ -36,6 +36,29 @@ func (s *LoggerSuite) TestInheritedLabels(c *gc.C) { logger := context.GetLogger("testing") + nestedLoggerWithLabels := logger. + ChildWithLabels("nested", loggo.Labels{"foo": "bar"}) + deepNestedLoggerWithLabels := nestedLoggerWithLabels. + ChildWithLabels("nested", loggo.Labels{"foo": "baz"}). + ChildWithLabels("deepnested", loggo.Labels{"fred": "tim"}) + + loggerWithTagsAndLabels := logger. + ChildWithLabels("nested-labels", loggo.Labels{"hello": "world"}). + ChildWithTags("nested-tag", "tag1", "tag2") + + c.Check(nestedLoggerWithLabels.Labels(), gc.DeepEquals, loggo.Labels{"foo": "bar"}) + c.Check(deepNestedLoggerWithLabels.Labels(), gc.DeepEquals, loggo.Labels{"foo": "baz", "fred": "tim"}) + c.Check(loggerWithTagsAndLabels.Labels(), gc.DeepEquals, loggo.Labels{"hello": "world"}) +} + +func (s *LoggerSuite) TestInheritedLabelsInLogs(c *gc.C) { + writer := &loggo.TestWriter{} + context := loggo.NewContext(loggo.INFO) + err := context.AddWriter("test", writer) + c.Assert(err, gc.IsNil) + + logger := context.GetLogger("testing") + nestedLoggerWithLabels := logger. ChildWithLabels("nested", loggo.Labels{"foo": "bar"}) deepNestedLoggerWithLabels := nestedLoggerWithLabels.