Add support for configuration static logging fields

To allow flexibility in log message context information, this changeset
provides the ability to configure static fields that are included in the
context. Such fields can be set via configuration or environment variables.

Signed-off-by: Stephen J Day <stephen.day@docker.com>

cmd/registry/config.yml

@@ -1,6 +1,9 @@
 version: 0.1
 log:
   level: debug
+  fields:
+    service: registry
+    environment: development
 storage:
     filesystem:
         rootdirectory: /tmp/registry-dev

cmd/registry/main.go

@@ -50,13 +50,11 @@ func main() {
 		fatalf("configuration error: %v", err)
 	}
 
-	if err := configureLogging(config); err != nil {
+	ctx, err = configureLogging(ctx, config)
+	if err != nil {
 		fatalf("error configuring logger: %v", err)
 	}
 
-	ctx = context.WithValue(ctx, "version", version.Version)
-	ctx = ctxu.WithLogger(ctx, ctxu.GetLogger(ctx, "version"))
-
 	app := handlers.NewApp(ctx, *config)
 	handler := configureReporting(app)
 	handler = gorhandlers.CombinedLoggingHandler(os.Stdout, handler)
@@ -151,13 +149,14 @@ func configureReporting(app *handlers.App) http.Handler {
 	return handler
 }
 
-// configureLogging the default logger using the configuration. Must be called
-// before creating any contextual loggers.
-func configureLogging(config *configuration.Configuration) error {
+// configureLogging prepares the context with a logger using the
+// configuration.
+func configureLogging(ctx context.Context, config *configuration.Configuration) (context.Context, error) {
 	if config.Log.Level == "" && config.Log.Formatter == "" {
 		// If no config for logging is set, fallback to deprecated "Loglevel".
 		log.SetLevel(logLevel(config.Loglevel))
-		return nil
+		ctx = ctxu.WithLogger(ctx, ctxu.GetLogger(ctx, "version"))
+		return ctx, nil
 	}
 
 	log.SetLevel(logLevel(config.Log.Level))
@@ -168,11 +167,11 @@ func configureLogging(config *configuration.Configuration) error {
 	case "text":
 		log.SetFormatter(&log.TextFormatter{})
 	case "logstash":
-		log.SetFormatter(&logstash.LogstashFormatter{Type: "registry"})
+		log.SetFormatter(&logstash.LogstashFormatter{})
 	default:
 		// just let the library use default on empty string.
 		if config.Log.Formatter != "" {
-			return fmt.Errorf("unsupported logging formatter: %q", config.Log.Formatter)
+			return ctx, fmt.Errorf("unsupported logging formatter: %q", config.Log.Formatter)
 		}
 	}
 
@@ -180,7 +179,21 @@ func configureLogging(config *configuration.Configuration) error {
 		log.Debugf("using %q logging formatter", config.Log.Formatter)
 	}
 
-	return nil
+	// log the application version with messages
+	ctx = context.WithValue(ctx, "version", version.Version)
+
+	if len(config.Log.Fields) > 0 {
+		// build up the static fields, if present.
+		var fields []interface{}
+		for k := range config.Log.Fields {
+			fields = append(fields, k)
+		}
+
+		ctx = withMapContext(ctx, config.Log.Fields)
+		ctx = ctxu.WithLogger(ctx, ctxu.GetLogger(ctx, fields...))
+	}
+
+	return ctx, nil
 }
 
 func logLevel(level configuration.Loglevel) log.Level {
@@ -193,6 +206,36 @@ func logLevel(level configuration.Loglevel) log.Level {
 	return l
 }
 
+// stringMapContext is a simple context implementation that checks a map for a
+// key, falling back to a parent if not present.
+type stringMapContext struct {
+	context.Context
+	m map[string]string
+}
+
+// withMapContext returns a context that proxies lookups through a map.
+func withMapContext(ctx context.Context, m map[string]string) context.Context {
+	mo := make(map[string]string, len(m)) // make our own copy.
+	for k, v := range m {
+		mo[k] = v
+	}
+
+	return stringMapContext{
+		Context: ctx,
+		m:       mo,
+	}
+}
+
+func (smc stringMapContext) Value(key interface{}) interface{} {
+	if ks, ok := key.(string); ok {
+		if v, ok := smc.m[ks]; ok {
+			return v
+		}
+	}
+
+	return smc.Context.Value(key)
+}
+
 // debugServer starts the debug server with pprof, expvar among other
 // endpoints. The addr should not be exposed externally. For most of these to
 // work, tls cannot be enabled on the endpoint, so it is generally separate.

configuration/configuration.go

@@ -25,6 +25,10 @@ type Configuration struct {
 		// Formatter overrides the default formatter with another. Options
 		// include "text", "json" and "logstash".
 		Formatter string `yaml:"formatter"`
+
+		// Fields allows users to specify static string fields to include in
+		// the logger context.
+		Fields map[string]string `yaml:"fields"`
 	}
 
 	// Loglevel is the level at which registry operations are logged. This is

configuration/configuration_test.go

@@ -16,6 +16,13 @@ func Test(t *testing.T) { TestingT(t) }
 // configStruct is a canonical example configuration, which should map to configYamlV0_1
 var configStruct = Configuration{
 	Version: "0.1",
+	Log: struct {
+		Level     Loglevel          `yaml:"level"`
+		Formatter string            `yaml:"formatter"`
+		Fields    map[string]string `yaml:"fields"`
+	}{
+		Fields: map[string]string{"environment": "test"},
+	},
 	Loglevel: "info",
 	Storage: Storage{
 		"s3": Parameters{
@@ -57,6 +64,9 @@ var configStruct = Configuration{
 // configYamlV0_1 is a Version 0.1 yaml document representing configStruct
 var configYamlV0_1 = `
 version: 0.1
+log:
+  fields:
+    environment: test
 loglevel: info
 storage:
   s3:
@@ -136,6 +146,7 @@ func (suite *ConfigSuite) TestParseSimple(c *C) {
 func (suite *ConfigSuite) TestParseInmemory(c *C) {
 	suite.expectedConfig.Storage = Storage{"inmemory": Parameters{}}
 	suite.expectedConfig.Reporting = Reporting{}
+	suite.expectedConfig.Log.Fields = nil
 
 	config, err := Parse(bytes.NewReader([]byte(inmemoryConfigYamlV0_1)))
 	c.Assert(err, IsNil)
@@ -150,6 +161,7 @@ func (suite *ConfigSuite) TestParseIncomplete(c *C) {
 	_, err := Parse(bytes.NewReader([]byte(incompleteConfigYaml)))
 	c.Assert(err, NotNil)
 
+	suite.expectedConfig.Log.Fields = nil
 	suite.expectedConfig.Storage = Storage{"filesystem": Parameters{"rootdirectory": "/tmp/testroot"}}
 	suite.expectedConfig.Auth = Auth{"silly": Parameters{"realm": "silly"}}
 	suite.expectedConfig.Reporting = Reporting{}
@@ -303,6 +315,12 @@ func copyConfig(config Configuration) *Configuration {
 
 	configCopy.Version = MajorMinorVersion(config.Version.Major(), config.Version.Minor())
 	configCopy.Loglevel = config.Loglevel
+	configCopy.Log = config.Log
+	configCopy.Log.Fields = make(map[string]string, len(config.Log.Fields))
+	for k, v := range config.Log.Fields {
+		configCopy.Log.Fields[k] = v
+	}
+
 	configCopy.Storage = Storage{config.Storage.Type(): Parameters{}}
 	for k, v := range config.Storage.Parameters() {
 		configCopy.Storage.setParameter(k, v)

doc/configuration.md

@@ -7,6 +7,9 @@ version: 0.1
 log:
 	level: debug
 	formatter: text
+	fields:
+		service: registry
+		environment: staging
 loglevel: debug # deprecated: use "log"
 storage:
 	filesystem:
@@ -100,6 +103,9 @@ messages can be adjusted with this configuration section.
 log:
 	level: debug
 	formatter: text
+	fields:
+		service: registry
+		environment: staging
 ```
 
 - level: **Optional** - Sets the sensitivity of logging output. Permitted
@@ -107,6 +113,9 @@ log:
 - formatter: **Optional** - This selects the format of logging output, which
   mostly affects how keyed attributes for a log line are encoded. Options are
   "text", "json" or "logstash". The default is "text".
+- fields: **Optional** - A map of field names to values that will be added to
+  every log line for the context. This is useful for identifying log messages
+  source after being mixed in other systems.
 
 ## loglevel