From 00e6b0d2b8942d0fe042d341424de57039ddf454 Mon Sep 17 00:00:00 2001 From: Stephen J Day Date: Mon, 23 Mar 2015 20:09:19 -0700 Subject: [PATCH 1/3] Update logrus dependency in Godep Signed-off-by: Stephen J Day --- Godeps/Godeps.json | 4 +- .../src/github.com/Sirupsen/logrus/README.md | 65 +++------ .../Sirupsen/logrus/examples/basic/basic.go | 10 ++ .../Sirupsen/logrus/examples/hook/hook.go | 7 +- .../github.com/Sirupsen/logrus/exported.go | 2 + .../logrus/formatters/logstash/logstash.go | 48 +++++++ .../formatters/logstash/logstash_test.go | 52 +++++++ .../logrus/hooks/airbrake/airbrake.go | 58 ++++---- .../logrus/hooks/airbrake/airbrake_test.go | 133 ++++++++++++++++++ .../Sirupsen/logrus/hooks/bugsnag/bugsnag.go | 68 +++++++++ .../logrus/hooks/bugsnag/bugsnag_test.go | 64 +++++++++ .../Sirupsen/logrus/hooks/sentry/README.md | 2 +- .../Sirupsen/logrus/json_formatter.go | 9 +- .../Sirupsen/logrus/json_formatter_test.go | 120 ++++++++++++++++ .../src/github.com/Sirupsen/logrus/logger.go | 84 ++++++++--- .../github.com/Sirupsen/logrus/logrus_test.go | 18 +++ .../Sirupsen/logrus/terminal_notwindows.go | 2 +- .../Sirupsen/logrus/terminal_openbsd.go | 1 - .../Sirupsen/logrus/text_formatter.go | 43 ++++-- .../Sirupsen/logrus/text_formatter_test.go | 4 + .../src/github.com/Sirupsen/logrus/writer.go | 2 +- 21 files changed, 677 insertions(+), 119 deletions(-) create mode 100644 Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash.go create mode 100644 Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash_test.go create mode 100644 Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/airbrake/airbrake_test.go create mode 100644 Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/bugsnag/bugsnag.go create mode 100644 Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/bugsnag/bugsnag_test.go create mode 100644 Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter_test.go diff --git a/Godeps/Godeps.json b/Godeps/Godeps.json index 8ed67319..15bd4dd8 100644 --- a/Godeps/Godeps.json +++ b/Godeps/Godeps.json @@ -29,8 +29,8 @@ }, { "ImportPath": "github.com/Sirupsen/logrus", - "Comment": "v0.6.4-12-g467d9d5", - "Rev": "467d9d55c2d2c17248441a8fc661561161f40d5e" + "Comment": "v0.7.1", + "Rev": "3fc34d061b9c78a70db853c7cb6b0576b6d4f32d" }, { "ImportPath": "github.com/bugsnag/bugsnag-go", diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/README.md b/Godeps/_workspace/src/github.com/Sirupsen/logrus/README.md index 6227b3f3..512f26e5 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/README.md +++ b/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 -control your Logrus to make sure you aren't fetching latest `master` on every -build.** +yet stable (pre 1.0). Logrus itself is completely stable and has been used in +many large deployments. The core API is unlikely to change much but please +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 -// Not the real implementation of the Airbrake hook. Just a simple sample. -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`: +Logrus comes with [built-in hooks](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. diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/examples/basic/basic.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/examples/basic/basic.go index a62ba45d..a1623ec0 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/examples/basic/basic.go +++ b/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, diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/examples/hook/hook.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/examples/hook/hook.go index 42e7a4c9..cb5759a3 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/examples/hook/hook.go +++ b/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, diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/exported.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/exported.go index fd092fc7..a67e1b80 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/exported.go +++ b/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 } diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash.go new file mode 100644 index 00000000..34b1ccbc --- /dev/null +++ b/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 +} diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash_test.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash_test.go new file mode 100644 index 00000000..d8814a0e --- /dev/null +++ b/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"]) +} diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/airbrake/airbrake.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/airbrake/airbrake.go index 880d21ec..b0502c33 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/airbrake/airbrake.go +++ b/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: -// * airbrake.Endpoint -// * airbrake.ApiKey -// * airbrake.Environment (only sends exceptions when set to "production") -// -// 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{} +// with the Airbrake API. +type airbrakeHook struct { + APIKey string + Endpoint string + Environment string +} -func (hook *AirbrakeHook) Fire(entry *logrus.Entry) error { - if entry.Data["error"] == nil { - entry.Logger.WithFields(logrus.Fields{ - "source": "airbrake", - "endpoint": airbrake.Endpoint, - }).Warn("Exceptions sent to Airbrake must have an 'error' key with the error") - return nil +func NewHook(endpoint, apiKey, env string) *airbrakeHook { + return &airbrakeHook{ + APIKey: apiKey, + Endpoint: endpoint, + Environment: env, } +} +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 { - entry.Logger.WithFields(logrus.Fields{ - "source": "airbrake", - "endpoint": airbrake.Endpoint, - }).Warn("Exceptions sent to Airbrake must have an `error` key of type `error`") - return nil + if ok { + notifyErr = err + } else { + notifyErr = errors.New(entry.Message) } - airErr := airbrake.Notify(err) + airErr := airbrake.Notify(notifyErr) if airErr != nil { - entry.Logger.WithFields(logrus.Fields{ - "source": "airbrake", - "endpoint": airbrake.Endpoint, - "error": airErr, - }).Warn("Failed to send error to Airbrake") + return fmt.Errorf("Failed to send error to Airbrake: %s", airErr) } return nil } -func (hook *AirbrakeHook) Levels() []logrus.Level { +func (hook *airbrakeHook) Levels() []logrus.Level { return []logrus.Level{ logrus.ErrorLevel, logrus.FatalLevel, diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/airbrake/airbrake_test.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/airbrake/airbrake_test.go new file mode 100644 index 00000000..058a91e3 --- /dev/null +++ b/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(¬ice); err != nil { + t.Error(err) + } + r.Body.Close() + + noticeError <- notice.Error + })) + + return ts +} diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/bugsnag/bugsnag.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/bugsnag/bugsnag.go new file mode 100644 index 00000000..d20a0f54 --- /dev/null +++ b/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, + } +} diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/bugsnag/bugsnag_test.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/bugsnag/bugsnag_test.go new file mode 100644 index 00000000..e9ea298d --- /dev/null +++ b/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, ¬ice); 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") + } +} diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/sentry/README.md b/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/sentry/README.md index a409f3b0..19e58bb4 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks/sentry/README.md +++ b/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 ``` diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter.go index b09227c2..5c4c44bb 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter.go +++ b/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) diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter_test.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter_test.go new file mode 100644 index 00000000..1d708732 --- /dev/null +++ b/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") + } +} diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/logger.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/logger.go index b392e547..da928a37 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/logger.go +++ b/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...) + } } diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/logrus_test.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/logrus_test.go index 7f52c6fb..d85dba4d 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/logrus_test.go +++ b/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() +} diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_notwindows.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_notwindows.go index 80edd323..b8bebc13 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_notwindows.go +++ b/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 diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_openbsd.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_openbsd.go index d238bfa0..af609a53 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_openbsd.go +++ b/Godeps/_workspace/src/github.com/Sirupsen/logrus/terminal_openbsd.go @@ -1,4 +1,3 @@ - package logrus import "syscall" diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter.go index 78e78893..0a06a110 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter.go +++ b/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 + var keys []string = make([]string, 0, len(entry.Data)) 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 } diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter_test.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter_test.go index f604f1b0..28a94990 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter_test.go +++ b/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. diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/writer.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/writer.go index 90d3e01b..1e30b1c7 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/writer.go +++ b/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) From a75f0f26f7ecaae997c0b446e18cea49c74ab318 Mon Sep 17 00:00:00 2001 From: Stephen J Day Date: Mon, 23 Mar 2015 20:13:35 -0700 Subject: [PATCH 2/3] Allow logging formatter to be configured This changeset simply adds hooks into the configuration system to support multiple different kinds of output formats. These formatters are provided by logrus and include options such as "text" and "json". The configuraiton documentation has been updated accordingly. Signed-off-by: Stephen J Day --- cmd/registry/config.yml | 3 +- cmd/registry/main.go | 58 +++++++++++++++++++++++++++------- configuration/configuration.go | 14 +++++++- doc/configuration.md | 33 +++++++++++++++---- 4 files changed, 88 insertions(+), 20 deletions(-) diff --git a/cmd/registry/config.yml b/cmd/registry/config.yml index bb3ade11..a73644f0 100644 --- a/cmd/registry/config.yml +++ b/cmd/registry/config.yml @@ -1,5 +1,6 @@ version: 0.1 -loglevel: debug +log: + level: debug storage: filesystem: rootdirectory: /tmp/registry-dev diff --git a/cmd/registry/main.go b/cmd/registry/main.go index 6c442895..eb71267e 100644 --- a/cmd/registry/main.go +++ b/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,7 +50,10 @@ func main() { fatalf("configuration error: %v", err) } - log.SetLevel(logLevel(config.Loglevel)) + if err := configureLogging(config); err != nil { + fatalf("error configuring logger: %v", err) + } + ctx = context.WithValue(ctx, "version", version.Version) ctx = ctxu.WithLogger(ctx, ctxu.GetLogger(ctx, "version")) @@ -111,16 +115,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 +151,48 @@ 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 { + 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 + } + + 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{Type: "registry"}) + default: + // just let the library use default on empty string. + if config.Log.Formatter != "" { + return fmt.Errorf("unsupported logging formatter: %q", config.Log.Formatter) + } + } + + if config.Log.Formatter != "" { + log.Debugf("using %q logging formatter", config.Log.Formatter) + } + + return 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 +} + // 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. diff --git a/configuration/configuration.go b/configuration/configuration.go index 6c03b27f..c5bb035f 100644 --- a/configuration/configuration.go +++ b/configuration/configuration.go @@ -16,7 +16,19 @@ 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"` + } + + // 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 diff --git a/doc/configuration.md b/doc/configuration.md index 9441116b..32c28c58 100644 --- a/doc/configuration.md +++ b/doc/configuration.md @@ -4,7 +4,10 @@ Below is a comprehensive example of all possible configuration options for the r ```yaml version: 0.1 -loglevel: debug +log: + level: debug + formatter: text +loglevel: debug # deprecated: use "log" storage: filesystem: rootdirectory: /tmp/registry @@ -87,18 +90,34 @@ 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 +``` + +- 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". + ## 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: - -- ```error``` -- ```warn``` -- ```info``` -- ```debug``` +Permitted values are `error`, `warn`, `info` and `debug`. The default is +`info`. ## storage From ac73963d7e6e54714fdf6d017de7b9b2051bb6f2 Mon Sep 17 00:00:00 2001 From: Stephen J Day Date: Tue, 24 Mar 2015 17:12:04 -0700 Subject: [PATCH 3/3] 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 --- cmd/registry/config.yml | 3 ++ cmd/registry/main.go | 65 ++++++++++++++++++++++++----- configuration/configuration.go | 4 ++ configuration/configuration_test.go | 20 ++++++++- doc/configuration.md | 9 ++++ 5 files changed, 89 insertions(+), 12 deletions(-) diff --git a/cmd/registry/config.yml b/cmd/registry/config.yml index a73644f0..57541e41 100644 --- a/cmd/registry/config.yml +++ b/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 diff --git a/cmd/registry/main.go b/cmd/registry/main.go index eb71267e..5708a285 100644 --- a/cmd/registry/main.go +++ b/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. diff --git a/configuration/configuration.go b/configuration/configuration.go index c5bb035f..add62f50 100644 --- a/configuration/configuration.go +++ b/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 diff --git a/configuration/configuration_test.go b/configuration/configuration_test.go index 5a6abf90..47924501 100644 --- a/configuration/configuration_test.go +++ b/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) diff --git a/doc/configuration.md b/doc/configuration.md index 32c28c58..a94429b5 100644 --- a/doc/configuration.md +++ b/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