Merge pull request #293 from stevvooe/log-formatter-configuration

main, configuration, doc: allow logging formatter to be configured

Godeps/Godeps.json

@@ -29,8 +29,8 @@
 		},
 		{
 			"ImportPath": "github.com/Sirupsen/logrus",
-			"Comment": "v0.6.4-12-g467d9d5",
+			"Comment": "v0.7.1",
-			"Rev": "467d9d55c2d2c17248441a8fc661561161f40d5e"
+			"Rev": "3fc34d061b9c78a70db853c7cb6b0576b6d4f32d"
 		},
 		{
 			"ImportPath": "github.com/bugsnag/bugsnag-go",

Godeps/_workspace/src/github.com/Sirupsen/logrus/README.md

@@ -2,9 +2,10 @@
 
 Logrus is a structured logger for Go (golang), completely API compatible with
 the standard library logger. [Godoc][godoc]. **Please note the Logrus API is not
-yet stable (pre 1.0), the core API is unlikely to change much but please version
+yet stable (pre 1.0). Logrus itself is completely stable and has been used in
-control your Logrus to make sure you aren't fetching latest `master` on every
+many large deployments. The core API is unlikely to change much but please
-build.**
+version control your Logrus to make sure you aren't fetching latest `master` on
+every build.**
 
 Nicely color-coded in development (when a TTY is attached, otherwise just
 plain text):
@@ -81,7 +82,7 @@ func init() {
 
   // Use the Airbrake hook to report errors that have Error severity or above to
   // an exception tracker. You can create custom hooks, see the Hooks section.
-  log.AddHook(&logrus_airbrake.AirbrakeHook{})
+  log.AddHook(airbrake.NewHook("https://example.com", "xyz", "development"))
 
   // Output to stderr instead of stdout, could also be a file.
   log.SetOutput(os.Stderr)
@@ -163,43 +164,8 @@ You can add hooks for logging levels. For example to send errors to an exception
 tracking service on `Error`, `Fatal` and `Panic`, info to StatsD or log to
 multiple places simultaneously, e.g. syslog.
 
-```go
+Logrus comes with [built-in hooks](hooks/). Add those, or your custom hook, in
-// Not the real implementation of the Airbrake hook. Just a simple sample.
+`init`:
-import (
-  log "github.com/Sirupsen/logrus"
-)
-
-func init() {
-  log.AddHook(new(AirbrakeHook))
-}
-
-type AirbrakeHook struct{}
-
-// `Fire()` takes the entry that the hook is fired for. `entry.Data[]` contains
-// the fields for the entry. See the Fields section of the README.
-func (hook *AirbrakeHook) Fire(entry *logrus.Entry) error {
-  err := airbrake.Notify(entry.Data["error"].(error))
-  if err != nil {
-    log.WithFields(log.Fields{
-      "source":   "airbrake",
-      "endpoint": airbrake.Endpoint,
-    }).Info("Failed to send error to Airbrake")
-  }
-
-  return nil
-}
-
-// `Levels()` returns a slice of `Levels` the hook is fired for.
-func (hook *AirbrakeHook) Levels() []log.Level {
-  return []log.Level{
-    log.ErrorLevel,
-    log.FatalLevel,
-    log.PanicLevel,
-  }
-}
-```
-
-Logrus comes with built-in hooks. Add those, or your custom hook, in `init`:
 
 ```go
 import (
@@ -210,7 +176,7 @@ import (
 )
 
 func init() {
-  log.AddHook(new(logrus_airbrake.AirbrakeHook))
+  log.AddHook(airbrake.NewHook("https://example.com", "xyz", "development"))
 
   hook, err := logrus_syslog.NewSyslogHook("udp", "localhost:514", syslog.LOG_INFO, "")
   if err != nil {
@@ -232,6 +198,9 @@ func init() {
   Send errors to remote syslog server.
   Uses standard library `log/syslog` behind the scenes.
 
+* [`github.com/Sirupsen/logrus/hooks/bugsnag`](https://github.com/Sirupsen/logrus/blob/master/hooks/bugsnag/bugsnag.go)
+  Send errors to the Bugsnag exception tracking service.
+
 * [`github.com/nubo/hiprus`](https://github.com/nubo/hiprus)
   Send errors to a channel in hipchat.
 
@@ -241,6 +210,9 @@ func init() {
 * [`github.com/johntdyer/slackrus`](https://github.com/johntdyer/slackrus)
   Hook for Slack chat.
 
+* [`github.com/wercker/journalhook`](https://github.com/wercker/journalhook).
+  Hook for logging to `systemd-journald`.
+
 #### Level logging
 
 Logrus has six logging levels: Debug, Info, Warning, Error, Fatal and Panic.
@@ -317,6 +289,11 @@ The built-in logging formatters are:
     field to `true`.  To force no colored output even if there is a TTY  set the
     `DisableColors` field to `true`
 * `logrus.JSONFormatter`. Logs fields as JSON.
+* `logrus_logstash.LogstashFormatter`. Logs fields as Logstash Events (http://logstash.net).
+
+    ```go
+      logrus.SetFormatter(&logrus_logstash.LogstashFormatter{Type: “application_name"})
+    ```
 
 Third party logging formatters:
 
@@ -347,7 +324,7 @@ func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
 
 #### Logger as an `io.Writer`
 
-Logrus can be transormed into an `io.Writer`. That writer is the end of an `io.Pipe` and it is your responsability to close it.
+Logrus can be transormed into an `io.Writer`. That writer is the end of an `io.Pipe` and it is your responsibility to close it.
 
 ```go
 w := logger.Writer()
@@ -366,7 +343,7 @@ and hooks. The level for those entries is `info`.
 #### Rotation
 
 Log rotation is not provided with Logrus. Log rotation should be done by an
-external program (like `logrotated(8)`) that can compress and delete old log
+external program (like `logrotate(8)`) that can compress and delete old log
 entries. It should not be a feature of the application-level logger.
 
 

Godeps/_workspace/src/github.com/Sirupsen/logrus/examples/basic/basic.go

@@ -9,6 +9,7 @@ var log = logrus.New()
 func init() {
 	log.Formatter = new(logrus.JSONFormatter)
 	log.Formatter = new(logrus.TextFormatter) // default
+	log.Level = logrus.DebugLevel
 }
 
 func main() {
@@ -23,6 +24,11 @@ func main() {
 		}
 	}()
 
+	log.WithFields(logrus.Fields{
+		"animal": "walrus",
+		"number": 8,
+	}).Debug("Started observing beach")
+
 	log.WithFields(logrus.Fields{
 		"animal": "walrus",
 		"size":   10,
@@ -33,6 +39,10 @@ func main() {
 		"number": 122,
 	}).Warn("The group's number increased tremendously!")
 
+	log.WithFields(logrus.Fields{
+		"temperature": -4,
+	}).Debug("Temperature changes")
+
 	log.WithFields(logrus.Fields{
 		"animal": "orca",
 		"size":   9009,

Godeps/_workspace/src/github.com/Sirupsen/logrus/examples/hook/hook.go

@@ -3,21 +3,16 @@ package main
 import (
 	"github.com/Sirupsen/logrus"
 	"github.com/Sirupsen/logrus/hooks/airbrake"
-	"github.com/tobi/airbrake-go"
 )
 
 var log = logrus.New()
 
 func init() {
 	log.Formatter = new(logrus.TextFormatter) // default
-	log.Hooks.Add(new(logrus_airbrake.AirbrakeHook))
+	log.Hooks.Add(airbrake.NewHook("https://example.com", "xyz", "development"))
 }
 
 func main() {
-	airbrake.Endpoint = "https://exceptions.whatever.com/notifier_api/v2/notices.xml"
-	airbrake.ApiKey = "whatever"
-	airbrake.Environment = "production"
-
 	log.WithFields(logrus.Fields{
 		"animal": "walrus",
 		"size":   10,

Godeps/_workspace/src/github.com/Sirupsen/logrus/exported.go

@@ -36,6 +36,8 @@ func SetLevel(level Level) {
 
 // GetLevel returns the standard logger level.
 func GetLevel() Level {
+	std.mu.Lock()
+	defer std.mu.Unlock()
 	return std.Level
 }
 

Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash.go

@@ -0,0 +1,48 @@
+package logstash
+
+import (
+	"encoding/json"
+	"fmt"
+	"github.com/Sirupsen/logrus"
+	"time"
+)
+
+// Formatter generates json in logstash format.
+// Logstash site: http://logstash.net/
+type LogstashFormatter struct {
+	Type string // if not empty use for logstash type field.
+}
+
+func (f *LogstashFormatter) Format(entry *logrus.Entry) ([]byte, error) {
+	entry.Data["@version"] = 1
+	entry.Data["@timestamp"] = entry.Time.Format(time.RFC3339)
+
+	// set message field
+	v, ok := entry.Data["message"]
+	if ok {
+		entry.Data["fields.message"] = v
+	}
+	entry.Data["message"] = entry.Message
+
+	// set level field
+	v, ok = entry.Data["level"]
+	if ok {
+		entry.Data["fields.level"] = v
+	}
+	entry.Data["level"] = entry.Level.String()
+
+	// set type field
+	if f.Type != "" {
+		v, ok = entry.Data["type"]
+		if ok {
+			entry.Data["fields.type"] = v
+		}
+		entry.Data["type"] = f.Type
+	}
+
+	serialized, err := json.Marshal(entry.Data)
+	if err != nil {
+		return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
+	}
+	return append(serialized, '\n'), nil
+}

Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash_test.go

@@ -0,0 +1,52 @@
+package logstash
+
+import (
+	"bytes"
+	"encoding/json"
+	"github.com/Sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+	"testing"
+)
+
+func TestLogstashFormatter(t *testing.T) {
+	assert := assert.New(t)
+
+	lf := LogstashFormatter{Type: "abc"}
+
+	fields := logrus.Fields{
+		"message": "def",
+		"level":   "ijk",
+		"type":    "lmn",
+		"one":     1,
+		"pi":      3.14,
+		"bool":    true,
+	}
+
+	entry := logrus.WithFields(fields)
+	entry.Message = "msg"
+	entry.Level = logrus.InfoLevel
+
+	b, _ := lf.Format(entry)
+
+	var data map[string]interface{}
+	dec := json.NewDecoder(bytes.NewReader(b))
+	dec.UseNumber()
+	dec.Decode(&data)
+
+	// base fields
+	assert.Equal(json.Number("1"), data["@version"])
+	assert.NotEmpty(data["@timestamp"])
+	assert.Equal("abc", data["type"])
+	assert.Equal("msg", data["message"])
+	assert.Equal("info", data["level"])
+
+	// substituted fields
+	assert.Equal("def", data["fields.message"])
+	assert.Equal("ijk", data["fields.level"])
+	assert.Equal("lmn", data["fields.type"])
+
+	// formats
+	assert.Equal(json.Number("1"), data["one"])
+	assert.Equal(json.Number("3.14"), data["pi"])
+	assert.Equal(true, data["bool"])
+}

Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/airbrake/airbrake.go

@@ -1,51 +1,51 @@
-package logrus_airbrake
+package airbrake
 
 import (
+	"errors"
+	"fmt"
+
 	"github.com/Sirupsen/logrus"
 	"github.com/tobi/airbrake-go"
 )
 
 // AirbrakeHook to send exceptions to an exception-tracking service compatible
-// with the Airbrake API. You must set:
+// with the Airbrake API.
-// * airbrake.Endpoint
+type airbrakeHook struct {
-// * airbrake.ApiKey
+	APIKey      string
-// * airbrake.Environment (only sends exceptions when set to "production")
+	Endpoint    string
-//
+	Environment string
-// Before using this hook, to send an error. Entries that trigger an Error,
+}
-// Fatal or Panic should now include an "error" field to send to Airbrake.
-type AirbrakeHook struct{}
 
-func (hook *AirbrakeHook) Fire(entry *logrus.Entry) error {
+func NewHook(endpoint, apiKey, env string) *airbrakeHook {
-	if entry.Data["error"] == nil {
+	return &airbrakeHook{
-		entry.Logger.WithFields(logrus.Fields{
+		APIKey:      apiKey,
-			"source":   "airbrake",
+		Endpoint:    endpoint,
-			"endpoint": airbrake.Endpoint,
+		Environment: env,
-		}).Warn("Exceptions sent to Airbrake must have an 'error' key with the error")
-		return nil
 	}
+}
 
+func (hook *airbrakeHook) Fire(entry *logrus.Entry) error {
+	airbrake.ApiKey = hook.APIKey
+	airbrake.Endpoint = hook.Endpoint
+	airbrake.Environment = hook.Environment
+
+	var notifyErr error
 	err, ok := entry.Data["error"].(error)
-	if !ok {
+	if ok {
-		entry.Logger.WithFields(logrus.Fields{
+		notifyErr = err
-			"source":   "airbrake",
+	} else {
-			"endpoint": airbrake.Endpoint,
+		notifyErr = errors.New(entry.Message)
-		}).Warn("Exceptions sent to Airbrake must have an `error` key of type `error`")
-		return nil
 	}
 
-	airErr := airbrake.Notify(err)
+	airErr := airbrake.Notify(notifyErr)
 	if airErr != nil {
-		entry.Logger.WithFields(logrus.Fields{
+		return fmt.Errorf("Failed to send error to Airbrake: %s", airErr)
-			"source":   "airbrake",
-			"endpoint": airbrake.Endpoint,
-			"error":    airErr,
-		}).Warn("Failed to send error to Airbrake")
 	}
 
 	return nil
 }
 
-func (hook *AirbrakeHook) Levels() []logrus.Level {
+func (hook *airbrakeHook) Levels() []logrus.Level {
 	return []logrus.Level{
 		logrus.ErrorLevel,
 		logrus.FatalLevel,

Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/airbrake/airbrake_test.go

@@ -0,0 +1,133 @@
+package airbrake
+
+import (
+	"encoding/xml"
+	"net/http"
+	"net/http/httptest"
+	"testing"
+	"time"
+
+	"github.com/Sirupsen/logrus"
+)
+
+type notice struct {
+	Error NoticeError `xml:"error"`
+}
+type NoticeError struct {
+	Class   string `xml:"class"`
+	Message string `xml:"message"`
+}
+
+type customErr struct {
+	msg string
+}
+
+func (e *customErr) Error() string {
+	return e.msg
+}
+
+const (
+	testAPIKey    = "abcxyz"
+	testEnv       = "development"
+	expectedClass = "*airbrake.customErr"
+	expectedMsg   = "foo"
+	unintendedMsg = "Airbrake will not see this string"
+)
+
+var (
+	noticeError = make(chan NoticeError, 1)
+)
+
+// TestLogEntryMessageReceived checks if invoking Logrus' log.Error
+// method causes an XML payload containing the log entry message is received
+// by a HTTP server emulating an Airbrake-compatible endpoint.
+func TestLogEntryMessageReceived(t *testing.T) {
+	log := logrus.New()
+	ts := startAirbrakeServer(t)
+	defer ts.Close()
+
+	hook := NewHook(ts.URL, testAPIKey, "production")
+	log.Hooks.Add(hook)
+
+	log.Error(expectedMsg)
+
+	select {
+	case received := <-noticeError:
+		if received.Message != expectedMsg {
+			t.Errorf("Unexpected message received: %s", received.Message)
+		}
+	case <-time.After(time.Second):
+		t.Error("Timed out; no notice received by Airbrake API")
+	}
+}
+
+// TestLogEntryMessageReceived confirms that, when passing an error type using
+// logrus.Fields, a HTTP server emulating an Airbrake endpoint receives the
+// error message returned by the Error() method on the error interface
+// rather than the logrus.Entry.Message string.
+func TestLogEntryWithErrorReceived(t *testing.T) {
+	log := logrus.New()
+	ts := startAirbrakeServer(t)
+	defer ts.Close()
+
+	hook := NewHook(ts.URL, testAPIKey, "production")
+	log.Hooks.Add(hook)
+
+	log.WithFields(logrus.Fields{
+		"error": &customErr{expectedMsg},
+	}).Error(unintendedMsg)
+
+	select {
+	case received := <-noticeError:
+		if received.Message != expectedMsg {
+			t.Errorf("Unexpected message received: %s", received.Message)
+		}
+		if received.Class != expectedClass {
+			t.Errorf("Unexpected error class: %s", received.Class)
+		}
+	case <-time.After(time.Second):
+		t.Error("Timed out; no notice received by Airbrake API")
+	}
+}
+
+// TestLogEntryWithNonErrorTypeNotReceived confirms that, when passing a
+// non-error type using logrus.Fields, a HTTP server emulating an Airbrake
+// endpoint receives the logrus.Entry.Message string.
+//
+// Only error types are supported when setting the 'error' field using
+// logrus.WithFields().
+func TestLogEntryWithNonErrorTypeNotReceived(t *testing.T) {
+	log := logrus.New()
+	ts := startAirbrakeServer(t)
+	defer ts.Close()
+
+	hook := NewHook(ts.URL, testAPIKey, "production")
+	log.Hooks.Add(hook)
+
+	log.WithFields(logrus.Fields{
+		"error": expectedMsg,
+	}).Error(unintendedMsg)
+
+	select {
+	case received := <-noticeError:
+		if received.Message != unintendedMsg {
+			t.Errorf("Unexpected message received: %s", received.Message)
+		}
+	case <-time.After(time.Second):
+		t.Error("Timed out; no notice received by Airbrake API")
+	}
+}
+
+func startAirbrakeServer(t *testing.T) *httptest.Server {
+	ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		var notice notice
+		if err := xml.NewDecoder(r.Body).Decode(&notice); err != nil {
+			t.Error(err)
+		}
+		r.Body.Close()
+
+		noticeError <- notice.Error
+	}))
+
+	return ts
+}

Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/bugsnag/bugsnag.go

@@ -0,0 +1,68 @@
+package logrus_bugsnag
+
+import (
+	"errors"
+
+	"github.com/Sirupsen/logrus"
+	"github.com/bugsnag/bugsnag-go"
+)
+
+type bugsnagHook struct{}
+
+// ErrBugsnagUnconfigured is returned if NewBugsnagHook is called before
+// bugsnag.Configure. Bugsnag must be configured before the hook.
+var ErrBugsnagUnconfigured = errors.New("bugsnag must be configured before installing this logrus hook")
+
+// ErrBugsnagSendFailed indicates that the hook failed to submit an error to
+// bugsnag. The error was successfully generated, but `bugsnag.Notify()`
+// failed.
+type ErrBugsnagSendFailed struct {
+	err error
+}
+
+func (e ErrBugsnagSendFailed) Error() string {
+	return "failed to send error to Bugsnag: " + e.err.Error()
+}
+
+// NewBugsnagHook initializes a logrus hook which sends exceptions to an
+// exception-tracking service compatible with the Bugsnag API. Before using
+// this hook, you must call bugsnag.Configure(). The returned object should be
+// registered with a log via `AddHook()`
+//
+// Entries that trigger an Error, Fatal or Panic should now include an "error"
+// field to send to Bugsnag.
+func NewBugsnagHook() (*bugsnagHook, error) {
+	if bugsnag.Config.APIKey == "" {
+		return nil, ErrBugsnagUnconfigured
+	}
+	return &bugsnagHook{}, nil
+}
+
+// Fire forwards an error to Bugsnag. Given a logrus.Entry, it extracts the
+// "error" field (or the Message if the error isn't present) and sends it off.
+func (hook *bugsnagHook) Fire(entry *logrus.Entry) error {
+	var notifyErr error
+	err, ok := entry.Data["error"].(error)
+	if ok {
+		notifyErr = err
+	} else {
+		notifyErr = errors.New(entry.Message)
+	}
+
+	bugsnagErr := bugsnag.Notify(notifyErr)
+	if bugsnagErr != nil {
+		return ErrBugsnagSendFailed{bugsnagErr}
+	}
+
+	return nil
+}
+
+// Levels enumerates the log levels on which the error should be forwarded to
+// bugsnag: everything at or above the "Error" level.
+func (hook *bugsnagHook) Levels() []logrus.Level {
+	return []logrus.Level{
+		logrus.ErrorLevel,
+		logrus.FatalLevel,
+		logrus.PanicLevel,
+	}
+}

Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/bugsnag/bugsnag_test.go

@@ -0,0 +1,64 @@
+package logrus_bugsnag
+
+import (
+	"encoding/json"
+	"errors"
+	"io/ioutil"
+	"net/http"
+	"net/http/httptest"
+	"testing"
+	"time"
+
+	"github.com/Sirupsen/logrus"
+	"github.com/bugsnag/bugsnag-go"
+)
+
+type notice struct {
+	Events []struct {
+		Exceptions []struct {
+			Message string `json:"message"`
+		} `json:"exceptions"`
+	} `json:"events"`
+}
+
+func TestNoticeReceived(t *testing.T) {
+	msg := make(chan string, 1)
+	expectedMsg := "foo"
+
+	ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		var notice notice
+		data, _ := ioutil.ReadAll(r.Body)
+		if err := json.Unmarshal(data, &notice); err != nil {
+			t.Error(err)
+		}
+		_ = r.Body.Close()
+
+		msg <- notice.Events[0].Exceptions[0].Message
+	}))
+	defer ts.Close()
+
+	hook := &bugsnagHook{}
+
+	bugsnag.Configure(bugsnag.Configuration{
+		Endpoint:     ts.URL,
+		ReleaseStage: "production",
+		APIKey:       "12345678901234567890123456789012",
+		Synchronous:  true,
+	})
+
+	log := logrus.New()
+	log.Hooks.Add(hook)
+
+	log.WithFields(logrus.Fields{
+		"error": errors.New(expectedMsg),
+	}).Error("Bugsnag will not see this string")
+
+	select {
+	case received := <-msg:
+		if received != expectedMsg {
+			t.Errorf("Unexpected message received: %s", received)
+		}
+	case <-time.After(time.Second):
+		t.Error("Timed out; no notice received by Bugsnag API")
+	}
+}

Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/sentry/README.md

@@ -57,5 +57,5 @@ with a call to `NewSentryHook`. This can be changed by assigning a value to the
 
 ```go
 hook, _ := logrus_sentry.NewSentryHook(...)
-hook.Timeout = 20*time.Seconds
+hook.Timeout = 20*time.Second
 ```

Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter.go

@@ -11,7 +11,14 @@ type JSONFormatter struct{}
 func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
 	data := make(Fields, len(entry.Data)+3)
 	for k, v := range entry.Data {
-		data[k] = v
+		switch v := v.(type) {
+		case error:
+			// Otherwise errors are ignored by `encoding/json`
+			// https://github.com/Sirupsen/logrus/issues/137
+			data[k] = v.Error()
+		default:
+			data[k] = v
+		}
 	}
 	prefixFieldClashes(data)
 	data["time"] = entry.Time.Format(time.RFC3339)

Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter_test.go

@@ -0,0 +1,120 @@
+package logrus
+
+import (
+	"encoding/json"
+	"errors"
+
+	"testing"
+)
+
+func TestErrorNotLost(t *testing.T) {
+	formatter := &JSONFormatter{}
+
+	b, err := formatter.Format(WithField("error", errors.New("wild walrus")))
+	if err != nil {
+		t.Fatal("Unable to format entry: ", err)
+	}
+
+	entry := make(map[string]interface{})
+	err = json.Unmarshal(b, &entry)
+	if err != nil {
+		t.Fatal("Unable to unmarshal formatted entry: ", err)
+	}
+
+	if entry["error"] != "wild walrus" {
+		t.Fatal("Error field not set")
+	}
+}
+
+func TestErrorNotLostOnFieldNotNamedError(t *testing.T) {
+	formatter := &JSONFormatter{}
+
+	b, err := formatter.Format(WithField("omg", errors.New("wild walrus")))
+	if err != nil {
+		t.Fatal("Unable to format entry: ", err)
+	}
+
+	entry := make(map[string]interface{})
+	err = json.Unmarshal(b, &entry)
+	if err != nil {
+		t.Fatal("Unable to unmarshal formatted entry: ", err)
+	}
+
+	if entry["omg"] != "wild walrus" {
+		t.Fatal("Error field not set")
+	}
+}
+
+func TestFieldClashWithTime(t *testing.T) {
+	formatter := &JSONFormatter{}
+
+	b, err := formatter.Format(WithField("time", "right now!"))
+	if err != nil {
+		t.Fatal("Unable to format entry: ", err)
+	}
+
+	entry := make(map[string]interface{})
+	err = json.Unmarshal(b, &entry)
+	if err != nil {
+		t.Fatal("Unable to unmarshal formatted entry: ", err)
+	}
+
+	if entry["fields.time"] != "right now!" {
+		t.Fatal("fields.time not set to original time field")
+	}
+
+	if entry["time"] != "0001-01-01T00:00:00Z" {
+		t.Fatal("time field not set to current time, was: ", entry["time"])
+	}
+}
+
+func TestFieldClashWithMsg(t *testing.T) {
+	formatter := &JSONFormatter{}
+
+	b, err := formatter.Format(WithField("msg", "something"))
+	if err != nil {
+		t.Fatal("Unable to format entry: ", err)
+	}
+
+	entry := make(map[string]interface{})
+	err = json.Unmarshal(b, &entry)
+	if err != nil {
+		t.Fatal("Unable to unmarshal formatted entry: ", err)
+	}
+
+	if entry["fields.msg"] != "something" {
+		t.Fatal("fields.msg not set to original msg field")
+	}
+}
+
+func TestFieldClashWithLevel(t *testing.T) {
+	formatter := &JSONFormatter{}
+
+	b, err := formatter.Format(WithField("level", "something"))
+	if err != nil {
+		t.Fatal("Unable to format entry: ", err)
+	}
+
+	entry := make(map[string]interface{})
+	err = json.Unmarshal(b, &entry)
+	if err != nil {
+		t.Fatal("Unable to unmarshal formatted entry: ", err)
+	}
+
+	if entry["fields.level"] != "something" {
+		t.Fatal("fields.level not set to original level field")
+	}
+}
+
+func TestJSONEntryEndsWithNewline(t *testing.T) {
+	formatter := &JSONFormatter{}
+
+	b, err := formatter.Format(WithField("level", "something"))
+	if err != nil {
+		t.Fatal("Unable to format entry: ", err)
+	}
+
+	if b[len(b)-1] != '\n' {
+		t.Fatal("Expected JSON log entry to end with a newline")
+	}
+}

Godeps/_workspace/src/github.com/Sirupsen/logrus/logger.go

@@ -65,11 +65,15 @@ func (logger *Logger) WithFields(fields Fields) *Entry {
 }
 
 func (logger *Logger) Debugf(format string, args ...interface{}) {
-	NewEntry(logger).Debugf(format, args...)
+	if logger.Level >= DebugLevel {
+		NewEntry(logger).Debugf(format, args...)
+	}
 }
 
 func (logger *Logger) Infof(format string, args ...interface{}) {
-	NewEntry(logger).Infof(format, args...)
+	if logger.Level >= InfoLevel {
+		NewEntry(logger).Infof(format, args...)
+	}
 }
 
 func (logger *Logger) Printf(format string, args ...interface{}) {
@@ -77,31 +81,45 @@ func (logger *Logger) Printf(format string, args ...interface{}) {
 }
 
 func (logger *Logger) Warnf(format string, args ...interface{}) {
-	NewEntry(logger).Warnf(format, args...)
+	if logger.Level >= WarnLevel {
+		NewEntry(logger).Warnf(format, args...)
+	}
 }
 
 func (logger *Logger) Warningf(format string, args ...interface{}) {
-	NewEntry(logger).Warnf(format, args...)
+	if logger.Level >= WarnLevel {
+		NewEntry(logger).Warnf(format, args...)
+	}
 }
 
 func (logger *Logger) Errorf(format string, args ...interface{}) {
-	NewEntry(logger).Errorf(format, args...)
+	if logger.Level >= ErrorLevel {
+		NewEntry(logger).Errorf(format, args...)
+	}
 }
 
 func (logger *Logger) Fatalf(format string, args ...interface{}) {
-	NewEntry(logger).Fatalf(format, args...)
+	if logger.Level >= FatalLevel {
+		NewEntry(logger).Fatalf(format, args...)
+	}
 }
 
 func (logger *Logger) Panicf(format string, args ...interface{}) {
-	NewEntry(logger).Panicf(format, args...)
+	if logger.Level >= PanicLevel {
+		NewEntry(logger).Panicf(format, args...)
+	}
 }
 
 func (logger *Logger) Debug(args ...interface{}) {
-	NewEntry(logger).Debug(args...)
+	if logger.Level >= DebugLevel {
+		NewEntry(logger).Debug(args...)
+	}
 }
 
 func (logger *Logger) Info(args ...interface{}) {
-	NewEntry(logger).Info(args...)
+	if logger.Level >= InfoLevel {
+		NewEntry(logger).Info(args...)
+	}
 }
 
 func (logger *Logger) Print(args ...interface{}) {
@@ -109,31 +127,45 @@ func (logger *Logger) Print(args ...interface{}) {
 }
 
 func (logger *Logger) Warn(args ...interface{}) {
-	NewEntry(logger).Warn(args...)
+	if logger.Level >= WarnLevel {
+		NewEntry(logger).Warn(args...)
+	}
 }
 
 func (logger *Logger) Warning(args ...interface{}) {
-	NewEntry(logger).Warn(args...)
+	if logger.Level >= WarnLevel {
+		NewEntry(logger).Warn(args...)
+	}
 }
 
 func (logger *Logger) Error(args ...interface{}) {
-	NewEntry(logger).Error(args...)
+	if logger.Level >= ErrorLevel {
+		NewEntry(logger).Error(args...)
+	}
 }
 
 func (logger *Logger) Fatal(args ...interface{}) {
-	NewEntry(logger).Fatal(args...)
+	if logger.Level >= FatalLevel {
+		NewEntry(logger).Fatal(args...)
+	}
 }
 
 func (logger *Logger) Panic(args ...interface{}) {
-	NewEntry(logger).Panic(args...)
+	if logger.Level >= PanicLevel {
+		NewEntry(logger).Panic(args...)
+	}
 }
 
 func (logger *Logger) Debugln(args ...interface{}) {
-	NewEntry(logger).Debugln(args...)
+	if logger.Level >= DebugLevel {
+		NewEntry(logger).Debugln(args...)
+	}
 }
 
 func (logger *Logger) Infoln(args ...interface{}) {
-	NewEntry(logger).Infoln(args...)
+	if logger.Level >= InfoLevel {
+		NewEntry(logger).Infoln(args...)
+	}
 }
 
 func (logger *Logger) Println(args ...interface{}) {
@@ -141,21 +173,31 @@ func (logger *Logger) Println(args ...interface{}) {
 }
 
 func (logger *Logger) Warnln(args ...interface{}) {
-	NewEntry(logger).Warnln(args...)
+	if logger.Level >= WarnLevel {
+		NewEntry(logger).Warnln(args...)
+	}
 }
 
 func (logger *Logger) Warningln(args ...interface{}) {
-	NewEntry(logger).Warnln(args...)
+	if logger.Level >= WarnLevel {
+		NewEntry(logger).Warnln(args...)
+	}
 }
 
 func (logger *Logger) Errorln(args ...interface{}) {
-	NewEntry(logger).Errorln(args...)
+	if logger.Level >= ErrorLevel {
+		NewEntry(logger).Errorln(args...)
+	}
 }
 
 func (logger *Logger) Fatalln(args ...interface{}) {
-	NewEntry(logger).Fatalln(args...)
+	if logger.Level >= FatalLevel {
+		NewEntry(logger).Fatalln(args...)
+	}
 }
 
 func (logger *Logger) Panicln(args ...interface{}) {
-	NewEntry(logger).Panicln(args...)
+	if logger.Level >= PanicLevel {
+		NewEntry(logger).Panicln(args...)
+	}
 }

Godeps/_workspace/src/github.com/Sirupsen/logrus/logrus_test.go

@@ -5,6 +5,7 @@ import (
 	"encoding/json"
 	"strconv"
 	"strings"
+	"sync"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
@@ -281,3 +282,20 @@ func TestParseLevel(t *testing.T) {
 	l, err = ParseLevel("invalid")
 	assert.Equal(t, "not a valid logrus Level: \"invalid\"", err.Error())
 }
+
+func TestGetSetLevelRace(t *testing.T) {
+	wg := sync.WaitGroup{}
+	for i := 0; i < 100; i++ {
+		wg.Add(1)
+		go func(i int) {
+			defer wg.Done()
+			if i%2 == 0 {
+				SetLevel(InfoLevel)
+			} else {
+				GetLevel()
+			}
+		}(i)
+
+	}
+	wg.Wait()
+}

Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_notwindows.go

@@ -3,7 +3,7 @@
 // Use of this source code is governed by a BSD-style
 // license that can be found in the LICENSE file.
 
-// +build linux,!appengine darwin freebsd openbsd
+// +build linux darwin freebsd openbsd
 
 package logrus
 

Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_openbsd.go

@@ -1,4 +1,3 @@
-
 package logrus
 
 import "syscall"

Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter.go

@@ -3,7 +3,6 @@ package logrus
 import (
 	"bytes"
 	"fmt"
-	"regexp"
 	"sort"
 	"strings"
 	"time"
@@ -15,12 +14,12 @@ const (
 	green   = 32
 	yellow  = 33
 	blue    = 34
+	gray    = 37
 )
 
 var (
 	baseTimestamp time.Time
 	isTerminal    bool
-	noQuoteNeeded *regexp.Regexp
 )
 
 func init() {
@@ -34,20 +33,34 @@ func miniTS() int {
 
 type TextFormatter struct {
 	// Set to true to bypass checking for a TTY before outputting colors.
-	ForceColors   bool
+	ForceColors bool
+
+	// Force disabling colors.
 	DisableColors bool
-	// Set to true to disable timestamp logging (useful when the output
+
-	// is redirected to a logging system already adding a timestamp)
+	// Disable timestamp logging. useful when output is redirected to logging
+	// system that already adds timestamps.
 	DisableTimestamp bool
+
+	// Enable logging the full timestamp when a TTY is attached instead of just
+	// the time passed since beginning of execution.
+	FullTimestamp bool
+
+	// The fields are sorted by default for a consistent output. For applications
+	// that log extremely frequently and don't use the JSON formatter this may not
+	// be desired.
+	DisableSorting bool
 }
 
 func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
-
+	var keys []string = make([]string, 0, len(entry.Data))
-	var keys []string
 	for k := range entry.Data {
 		keys = append(keys, k)
 	}
-	sort.Strings(keys)
+
+	if !f.DisableSorting {
+		sort.Strings(keys)
+	}
 
 	b := &bytes.Buffer{}
 
@@ -56,7 +69,7 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
 	isColored := (f.ForceColors || isTerminal) && !f.DisableColors
 
 	if isColored {
-		printColored(b, entry, keys)
+		f.printColored(b, entry, keys)
 	} else {
 		if !f.DisableTimestamp {
 			f.appendKeyValue(b, "time", entry.Time.Format(time.RFC3339))
@@ -72,9 +85,11 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
 	return b.Bytes(), nil
 }
 
-func printColored(b *bytes.Buffer, entry *Entry, keys []string) {
+func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []string) {
 	var levelColor int
 	switch entry.Level {
+	case DebugLevel:
+		levelColor = gray
 	case WarnLevel:
 		levelColor = yellow
 	case ErrorLevel, FatalLevel, PanicLevel:
@@ -85,7 +100,11 @@ func printColored(b *bytes.Buffer, entry *Entry, keys []string) {
 
 	levelText := strings.ToUpper(entry.Level.String())[0:4]
 
-	fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d] %-44s ", levelColor, levelText, miniTS(), entry.Message)
+	if !f.FullTimestamp {
+		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d] %-44s ", levelColor, levelText, miniTS(), entry.Message)
+	} else {
+		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s] %-44s ", levelColor, levelText, entry.Time.Format(time.RFC3339), entry.Message)
+	}
 	for _, k := range keys {
 		v := entry.Data[k]
 		fmt.Fprintf(b, " \x1b[%dm%s\x1b[0m=%v", levelColor, k, v)
@@ -96,7 +115,7 @@ func needsQuoting(text string) bool {
 	for _, ch := range text {
 		if !((ch >= 'a' && ch <= 'z') ||
 			(ch >= 'A' && ch <= 'Z') ||
-			(ch >= '0' && ch < '9') ||
+			(ch >= '0' && ch <= '9') ||
 			ch == '-' || ch == '.') {
 			return false
 		}

Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter_test.go

@@ -25,9 +25,13 @@ func TestQuoting(t *testing.T) {
 
 	checkQuoting(false, "abcd")
 	checkQuoting(false, "v1.0")
+	checkQuoting(false, "1234567890")
 	checkQuoting(true, "/foobar")
 	checkQuoting(true, "x y")
 	checkQuoting(true, "x,y")
 	checkQuoting(false, errors.New("invalid"))
 	checkQuoting(true, errors.New("invalid argument"))
 }
+
+// TODO add tests for sorting etc., this requires a parser for the text
+// formatter output.

Godeps/_workspace/src/github.com/Sirupsen/logrus/writer.go

@@ -6,7 +6,7 @@ import (
 	"runtime"
 )
 
-func (logger *Logger) Writer() (*io.PipeWriter) {
+func (logger *Logger) Writer() *io.PipeWriter {
 	reader, writer := io.Pipe()
 
 	go logger.writerScanner(reader)

cmd/registry/config.yml

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

cmd/registry/main.go

@@ -9,6 +9,7 @@ import (
 	"os"
 
 	log "github.com/Sirupsen/logrus"
+	"github.com/Sirupsen/logrus/formatters/logstash"
 	"github.com/bugsnag/bugsnag-go"
 	"github.com/docker/distribution/configuration"
 	ctxu "github.com/docker/distribution/context"
@@ -49,9 +50,10 @@ func main() {
 		fatalf("configuration error: %v", err)
 	}
 
-	log.SetLevel(logLevel(config.Loglevel))
+	ctx, err = configureLogging(ctx, config)
-	ctx = context.WithValue(ctx, "version", version.Version)
+	if err != nil {
-	ctx = ctxu.WithLogger(ctx, ctxu.GetLogger(ctx, "version"))
+		fatalf("error configuring logger: %v", err)
+	}
 
 	app := handlers.NewApp(ctx, *config)
 	handler := configureReporting(app)
@@ -111,16 +113,6 @@ func resolveConfiguration() (*configuration.Configuration, error) {
 	return config, nil
 }
 
-func logLevel(level configuration.Loglevel) log.Level {
-	l, err := log.ParseLevel(string(level))
-	if err != nil {
-		log.Warnf("error parsing level %q: %v", level, err)
-		l = log.InfoLevel
-	}
-
-	return l
-}
-
 func configureReporting(app *handlers.App) http.Handler {
 	var handler http.Handler = app
 
@@ -157,6 +149,93 @@ func configureReporting(app *handlers.App) http.Handler {
 	return handler
 }
 
+// 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))
+		ctx = ctxu.WithLogger(ctx, ctxu.GetLogger(ctx, "version"))
+		return ctx, nil
+	}
+
+	log.SetLevel(logLevel(config.Log.Level))
+
+	switch config.Log.Formatter {
+	case "json":
+		log.SetFormatter(&log.JSONFormatter{})
+	case "text":
+		log.SetFormatter(&log.TextFormatter{})
+	case "logstash":
+		log.SetFormatter(&logstash.LogstashFormatter{})
+	default:
+		// just let the library use default on empty string.
+		if config.Log.Formatter != "" {
+			return ctx, fmt.Errorf("unsupported logging formatter: %q", config.Log.Formatter)
+		}
+	}
+
+	if config.Log.Formatter != "" {
+		log.Debugf("using %q logging formatter", config.Log.Formatter)
+	}
+
+	// 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 {
+	l, err := log.ParseLevel(string(level))
+	if err != nil {
+		l = log.InfoLevel
+		log.Warnf("error parsing level %q: %v, using %q	", level, err, l)
+	}
+
+	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

@@ -16,7 +16,23 @@ type Configuration struct {
 	// Version is the version which defines the format of the rest of the configuration
 	Version Version `yaml:"version"`
 
-	// Loglevel is the level at which registry operations are logged
+	// Log supports setting various parameters related to the logging
+	// subsystem.
+	Log struct {
+		// Level is the granularity at which registry operations are logged.
+		Level Loglevel `yaml:"level"`
+
+		// 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
+	// deprecated. Please use Log.Level in the future.
 	Loglevel Loglevel `yaml:"loglevel"`
 
 	// Storage is the configuration for the registry's storage driver

configuration/configuration_test.go

@@ -15,7 +15,14 @@ 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",
+	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

@@ -4,7 +4,13 @@ Below is a comprehensive example of all possible configuration options for the r
 
 ```yaml
 version: 0.1
-loglevel: debug
+log:
+	level: debug
+	formatter: text
+	fields:
+		service: registry
+		environment: staging
+loglevel: debug # deprecated: use "log"
 storage:
 	filesystem:
 		rootdirectory: /tmp/registry
@@ -87,18 +93,40 @@ The version option is **required** and indicates the version of the configuratio
 
 N.B. The version of the registry software may be found at [/version/version.go](https://github.com/docker/distribution/blob/master/version/version.go)
 
+## log
+
+The log subsection configures the behavior of the logging system. The logging
+system outputs everything to stdout. The granularity and format of the log
+messages can be adjusted with this configuration section.
+
+```yaml
+log:
+	level: debug
+	formatter: text
+	fields:
+		service: registry
+		environment: staging
+```
+
+- level: **Optional** - Sets the sensitivity of logging output. Permitted
+  values are `error`, `warn`, `info` and `debug`. The default is `info`.
+- 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
 
+> **DEPRECATED:** Please use [log](#log) instead.
+
 ```yaml
 loglevel: debug
 ```
 
-The loglevel option is **required** and sets the sensitivity of logging output. Permitted values are:
+Permitted values are `error`, `warn`, `info` and `debug`. The default is
-
+`info`.
-- ```error```
-- ```warn```
-- ```info```
-- ```debug```
 
 ## storage