From 85de3967aa930a7f13c671b5b5f2e6936d80596f Mon Sep 17 00:00:00 2001 From: Stephen J Day Date: Fri, 10 Apr 2015 13:54:53 -0700 Subject: [PATCH 1/2] Update logrus package for configurable TimestampFormat Signed-off-by: Stephen J Day --- Godeps/Godeps.json | 4 +- .../github.com/Sirupsen/logrus/CHANGELOG.md | 7 +++ .../src/github.com/Sirupsen/logrus/README.md | 57 +++++++++---------- .../github.com/Sirupsen/logrus/formatter.go | 4 ++ .../logrus/formatters/logstash/logstash.go | 12 +++- .../Sirupsen/logrus/json_formatter.go | 13 ++++- .../Sirupsen/logrus/text_formatter.go | 10 +++- .../Sirupsen/logrus/text_formatter_test.go | 26 ++++++++- 8 files changed, 94 insertions(+), 39 deletions(-) create mode 100644 Godeps/_workspace/src/github.com/Sirupsen/logrus/CHANGELOG.md diff --git a/Godeps/Godeps.json b/Godeps/Godeps.json index 4522c76b..dc643683 100644 --- a/Godeps/Godeps.json +++ b/Godeps/Godeps.json @@ -29,8 +29,8 @@ }, { "ImportPath": "github.com/Sirupsen/logrus", - "Comment": "v0.7.1", - "Rev": "3fc34d061b9c78a70db853c7cb6b0576b6d4f32d" + "Comment": "v0.7.3", + "Rev": "55eb11d21d2a31a3cc93838241d04800f52e823d" }, { "ImportPath": "github.com/bugsnag/bugsnag-go", diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/CHANGELOG.md b/Godeps/_workspace/src/github.com/Sirupsen/logrus/CHANGELOG.md new file mode 100644 index 00000000..eb72bff9 --- /dev/null +++ b/Godeps/_workspace/src/github.com/Sirupsen/logrus/CHANGELOG.md @@ -0,0 +1,7 @@ +# 0.7.3 + +formatter/\*: allow configuration of timestamp layout + +# 0.7.2 + +formatter/text: Add configuration option for time format (#158) diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/README.md b/Godeps/_workspace/src/github.com/Sirupsen/logrus/README.md index 512f26e5..d55f9092 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/README.md +++ b/Godeps/_workspace/src/github.com/Sirupsen/logrus/README.md @@ -37,11 +37,13 @@ attached, the output is compatible with the [logfmt](http://godoc.org/github.com/kr/logfmt) format: ```text -time="2014-04-20 15:36:23.830442383 -0400 EDT" level="info" msg="A group of walrus emerges from the ocean" animal="walrus" size=10 -time="2014-04-20 15:36:23.830584199 -0400 EDT" level="warning" msg="The group's number increased tremendously!" omg=true number=122 -time="2014-04-20 15:36:23.830596521 -0400 EDT" level="info" msg="A giant walrus appears!" animal="walrus" size=10 -time="2014-04-20 15:36:23.830611837 -0400 EDT" level="info" msg="Tremendously sized cow enters the ocean." animal="walrus" size=9 -time="2014-04-20 15:36:23.830626464 -0400 EDT" level="fatal" msg="The ice breaks!" omg=true number=100 +time="2015-03-26T01:27:38-04:00" level=debug msg="Started observing beach" animal=walrus number=8 +time="2015-03-26T01:27:38-04:00" level=info msg="A group of walrus emerges from the ocean" animal=walrus size=10 +time="2015-03-26T01:27:38-04:00" level=warning msg="The group's number increased tremendously!" number=122 omg=true +time="2015-03-26T01:27:38-04:00" level=debug msg="Temperature changes" temperature=-4 +time="2015-03-26T01:27:38-04:00" level=panic msg="It's over 9000!" animal=orca size=9009 +time="2015-03-26T01:27:38-04:00" level=fatal msg="The ice breaks!" err=&{0x2082280c0 map[animal:orca size:9009] 2015-03-26 01:27:38.441574009 -0400 EDT panic It's over 9000!} number=100 omg=true +exit status 1 ``` #### Example @@ -106,6 +108,16 @@ func main() { "omg": true, "number": 100, }).Fatal("The ice breaks!") + + // A common pattern is to re-use fields between logging statements by re-using + // the logrus.Entry returned from WithFields() + contextLogger := log.WithFields(log.Fields{ + "common": "this is a common field", + "other": "I also should be logged always", + }) + + contextLogger.Info("I'll be logged with common and other field") + contextLogger.Info("Me too") } ``` @@ -187,31 +199,18 @@ func init() { } ``` -* [`github.com/Sirupsen/logrus/hooks/airbrake`](https://github.com/Sirupsen/logrus/blob/master/hooks/airbrake/airbrake.go) - Send errors to an exception tracking service compatible with the Airbrake API. - Uses [`airbrake-go`](https://github.com/tobi/airbrake-go) behind the scenes. -* [`github.com/Sirupsen/logrus/hooks/papertrail`](https://github.com/Sirupsen/logrus/blob/master/hooks/papertrail/papertrail.go) - Send errors to the Papertrail hosted logging service via UDP. - -* [`github.com/Sirupsen/logrus/hooks/syslog`](https://github.com/Sirupsen/logrus/blob/master/hooks/syslog/syslog.go) - 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. - -* [`github.com/sebest/logrusly`](https://github.com/sebest/logrusly) - Send logs to Loggly (https://www.loggly.com/) - -* [`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`. +| Hook | Description | +| ----- | ----------- | +| [Airbrake](https://github.com/Sirupsen/logrus/blob/master/hooks/airbrake/airbrake.go) | Send errors to an exception tracking service compatible with the Airbrake API. Uses [`airbrake-go`](https://github.com/tobi/airbrake-go) behind the scenes. | +| [Papertrail](https://github.com/Sirupsen/logrus/blob/master/hooks/papertrail/papertrail.go) | Send errors to the Papertrail hosted logging service via UDP. | +| [Syslog](https://github.com/Sirupsen/logrus/blob/master/hooks/syslog/syslog.go) | Send errors to remote syslog server. Uses standard library `log/syslog` behind the scenes. | +| [BugSnag](https://github.com/Sirupsen/logrus/blob/master/hooks/bugsnag/bugsnag.go) | Send errors to the Bugsnag exception tracking service. | +| [Hiprus](https://github.com/nubo/hiprus) | Send errors to a channel in hipchat. | +| [Logrusly](https://github.com/sebest/logrusly) | Send logs to [Loggly](https://www.loggly.com/) | +| [Slackrus](https://github.com/johntdyer/slackrus) | Hook for Slack chat. | +| [Journalhook](https://github.com/wercker/journalhook) | Hook for logging to `systemd-journald` | +| [Graylog](https://github.com/gemnasium/logrus-hooks/tree/master/graylog) | Hook for logging to [Graylog](http://graylog2.org/) | #### Level logging diff --git a/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatter.go b/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatter.go index 038ce9fd..104d689f 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatter.go +++ b/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatter.go @@ -1,5 +1,9 @@ package logrus +import "time" + +const DefaultTimestampFormat = time.RFC3339 + // The Formatter interface is used to implement a custom Formatter. It takes an // `Entry`. It exposes all the fields, including the default ones: // 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 index 34b1ccbc..8ea93ddf 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash.go +++ b/Godeps/_workspace/src/github.com/Sirupsen/logrus/formatters/logstash/logstash.go @@ -3,19 +3,27 @@ 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. + + // TimestampFormat sets the format used for timestamps. + TimestampFormat string } func (f *LogstashFormatter) Format(entry *logrus.Entry) ([]byte, error) { entry.Data["@version"] = 1 - entry.Data["@timestamp"] = entry.Time.Format(time.RFC3339) + + if f.TimestampFormat == "" { + f.TimestampFormat = logrus.DefaultTimestampFormat + } + + entry.Data["@timestamp"] = entry.Time.Format(f.TimestampFormat) // set message field v, ok := entry.Data["message"] 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 5c4c44bb..dcc4f1d9 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter.go +++ b/Godeps/_workspace/src/github.com/Sirupsen/logrus/json_formatter.go @@ -3,10 +3,12 @@ package logrus import ( "encoding/json" "fmt" - "time" ) -type JSONFormatter struct{} +type JSONFormatter struct { + // TimestampFormat sets the format used for marshaling timestamps. + TimestampFormat string +} func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) { data := make(Fields, len(entry.Data)+3) @@ -21,7 +23,12 @@ func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) { } } prefixFieldClashes(data) - data["time"] = entry.Time.Format(time.RFC3339) + + if f.TimestampFormat == "" { + f.TimestampFormat = DefaultTimestampFormat + } + + data["time"] = entry.Time.Format(f.TimestampFormat) data["msg"] = entry.Message data["level"] = entry.Level.String() 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 0a06a110..612417ff 100644 --- a/Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter.go +++ b/Godeps/_workspace/src/github.com/Sirupsen/logrus/text_formatter.go @@ -46,6 +46,9 @@ type TextFormatter struct { // the time passed since beginning of execution. FullTimestamp bool + // TimestampFormat to use for display when a full timestamp is printed + TimestampFormat string + // 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. @@ -68,11 +71,14 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) { isColored := (f.ForceColors || isTerminal) && !f.DisableColors + if f.TimestampFormat == "" { + f.TimestampFormat = DefaultTimestampFormat + } if isColored { f.printColored(b, entry, keys) } else { if !f.DisableTimestamp { - f.appendKeyValue(b, "time", entry.Time.Format(time.RFC3339)) + f.appendKeyValue(b, "time", entry.Time.Format(f.TimestampFormat)) } f.appendKeyValue(b, "level", entry.Level.String()) f.appendKeyValue(b, "msg", entry.Message) @@ -103,7 +109,7 @@ func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []strin 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) + fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s] %-44s ", levelColor, levelText, entry.Time.Format(f.TimestampFormat), entry.Message) } for _, k := range keys { v := entry.Data[k] 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 28a94990..e25a44f6 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 @@ -3,8 +3,8 @@ package logrus import ( "bytes" "errors" - "testing" + "time" ) func TestQuoting(t *testing.T) { @@ -33,5 +33,29 @@ func TestQuoting(t *testing.T) { checkQuoting(true, errors.New("invalid argument")) } +func TestTimestampFormat(t *testing.T) { + checkTimeStr := func(format string) { + customFormatter := &TextFormatter{DisableColors: true, TimestampFormat: format} + customStr, _ := customFormatter.Format(WithField("test", "test")) + timeStart := bytes.Index(customStr, ([]byte)("time=")) + timeEnd := bytes.Index(customStr, ([]byte)("level=")) + timeStr := customStr[timeStart+5 : timeEnd-1] + if timeStr[0] == '"' && timeStr[len(timeStr)-1] == '"' { + timeStr = timeStr[1 : len(timeStr)-1] + } + if format == "" { + format = time.RFC3339 + } + _, e := time.Parse(format, (string)(timeStr)) + if e != nil { + t.Errorf("time string \"%s\" did not match provided time format \"%s\": %s", timeStr, format, e) + } + } + + checkTimeStr("2006-01-02T15:04:05.000000000Z07:00") + checkTimeStr("Mon Jan _2 15:04:05 2006") + checkTimeStr("") +} + // TODO add tests for sorting etc., this requires a parser for the text // formatter output. From e10094141fb8c00aa86c6730ff5e8fa7cc50b925 Mon Sep 17 00:00:00 2001 From: Stephen J Day Date: Fri, 10 Apr 2015 13:56:19 -0700 Subject: [PATCH 2/2] Use nanosecond granularity timestmaps in log messages Signed-off-by: Stephen J Day --- cmd/registry/main.go | 20 ++++++++++++++++---- 1 file changed, 16 insertions(+), 4 deletions(-) diff --git a/cmd/registry/main.go b/cmd/registry/main.go index dc2a5326..9b249bd3 100644 --- a/cmd/registry/main.go +++ b/cmd/registry/main.go @@ -10,6 +10,7 @@ import ( "net/http" _ "net/http/pprof" "os" + "time" log "github.com/Sirupsen/logrus" "github.com/Sirupsen/logrus/formatters/logstash" @@ -196,13 +197,24 @@ func configureLogging(ctx context.Context, config *configuration.Configuration) log.SetLevel(logLevel(config.Log.Level)) - switch config.Log.Formatter { + formatter := config.Log.Formatter + if formatter == "" { + formatter = "text" // default formatter + } + + switch formatter { case "json": - log.SetFormatter(&log.JSONFormatter{}) + log.SetFormatter(&log.JSONFormatter{ + TimestampFormat: time.RFC3339Nano, + }) case "text": - log.SetFormatter(&log.TextFormatter{}) + log.SetFormatter(&log.TextFormatter{ + TimestampFormat: time.RFC3339Nano, + }) case "logstash": - log.SetFormatter(&logstash.LogstashFormatter{}) + log.SetFormatter(&logstash.LogstashFormatter{ + TimestampFormat: time.RFC3339Nano, + }) default: // just let the library use default on empty string. if config.Log.Formatter != "" {