Make airbrake hook non-blocking

CHANGELOG.md

@@ -0,0 +1,3 @@
+# 0.7.2
+
+formatter/text: Add configuration option for time format (#158)

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
@@ -82,7 +84,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(airbrake.NewHook("https://example.com", "xyz", "development"))
+  log.AddHook(airbrake.NewHook(123, "xyz", "development"))
 
   // Output to stderr instead of stdout, could also be a file.
   log.SetOutput(os.Stderr)
@@ -176,7 +178,9 @@ import (
 )
 
 func init() {
-  log.AddHook(airbrake.NewHook("https://example.com", "xyz", "development"))
+  projectID := 123
+  apiKey := "xyz"
+  log.AddHook(airbrake.NewHook(projectID, apiKey, "development"))
 
   hook, err := logrus_syslog.NewSyslogHook("udp", "localhost:514", syslog.LOG_INFO, "")
   if err != nil {
@@ -187,31 +191,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
 

examples/hook/hook.go

@@ -9,7 +9,7 @@ var log = logrus.New()
 
 func init() {
 	log.Formatter = new(logrus.TextFormatter) // default
-	log.Hooks.Add(airbrake.NewHook("https://example.com", "xyz", "development"))
+	log.Hooks.Add(airbrake.NewHook(123, "xyz", "development"))
 }
 
 func main() {

hooks/airbrake/airbrake.go

@@ -3,46 +3,56 @@ package airbrake
 import (
 	"errors"
 	"fmt"
+	"os"
 
 	"github.com/Sirupsen/logrus"
-	"github.com/tobi/airbrake-go"
+	"github.com/airbrake/gobrake"
 )
 
+// Set graylog.BufSize = <value> _before_ calling NewHook
+var BufSize uint = 1024
+
 // AirbrakeHook to send exceptions to an exception-tracking service compatible
 // with the Airbrake API.
 type airbrakeHook struct {
-	APIKey      string
-	Endpoint    string
-	Environment string
+	Airbrake   *gobrake.Notifier
+	noticeChan chan *gobrake.Notice
 }
 
-func NewHook(endpoint, apiKey, env string) *airbrakeHook {
-	return &airbrakeHook{
-		APIKey:      apiKey,
-		Endpoint:    endpoint,
-		Environment: env,
+func NewHook(projectID int64, apiKey, env string) *airbrakeHook {
+	airbrake := gobrake.NewNotifier(projectID, apiKey)
+	airbrake.SetContext("environment", env)
+	hook := &airbrakeHook{
+		Airbrake:   airbrake,
+		noticeChan: make(chan *gobrake.Notice, BufSize),
 	}
+	go hook.fire()
+	return hook
 }
 
 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 {
 		notifyErr = err
 	} else {
 		notifyErr = errors.New(entry.Message)
 	}
+	notice := hook.Airbrake.Notice(notifyErr, nil, 3)
+	hook.noticeChan <- notice
+	return nil
+}
 
-	airErr := airbrake.Notify(notifyErr)
-	if airErr != nil {
-		return fmt.Errorf("Failed to send error to Airbrake: %s", airErr)
-	}
+// fire sends errors to airbrake when an entry is available on entryChan
+func (hook *airbrakeHook) fire() {
+	for {
+		notice := <-hook.noticeChan
 
-	return nil
+		if err := hook.Airbrake.SendNotice(notice); err != nil {
+			fmt.Fprintf(os.Stderr, "Failed to send error to Airbrake: %v\n", err)
+		}
+
+	}
 }
 
 func (hook *airbrakeHook) Levels() []logrus.Level {

hooks/airbrake/airbrake_test.go

@@ -1,23 +1,17 @@
 package airbrake
 
 import (
-	"encoding/xml"
+	"encoding/json"
+	"io/ioutil"
 	"net/http"
-	"net/http/httptest"
+	"strings"
 	"testing"
 	"time"
 
 	"github.com/Sirupsen/logrus"
+	"github.com/airbrake/gobrake"
 )
 
-type notice struct {
-	Error NoticeError `xml:"error"`
-}
-type NoticeError struct {
-	Class   string `xml:"class"`
-	Message string `xml:"message"`
-}
-
 type customErr struct {
 	msg string
 }
@@ -35,18 +29,15 @@ const (
 )
 
 var (
-	noticeError = make(chan NoticeError, 1)
+	noticeError = make(chan *gobrake.Error, 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")
+	hook := newTestHook()
 	log.Hooks.Add(hook)
 
 	log.Error(expectedMsg)
@@ -67,10 +58,7 @@ func TestLogEntryMessageReceived(t *testing.T) {
 // 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")
+	hook := newTestHook()
 	log.Hooks.Add(hook)
 
 	log.WithFields(logrus.Fields{
@@ -82,8 +70,8 @@ func TestLogEntryWithErrorReceived(t *testing.T) {
 		if received.Message != expectedMsg {
 			t.Errorf("Unexpected message received: %s", received.Message)
 		}
-		if received.Class != expectedClass {
-			t.Errorf("Unexpected error class: %s", received.Class)
+		if received.Type != expectedClass {
+			t.Errorf("Unexpected error class: %s", received.Type)
 		}
 	case <-time.After(time.Second):
 		t.Error("Timed out; no notice received by Airbrake API")
@@ -98,10 +86,7 @@ func TestLogEntryWithErrorReceived(t *testing.T) {
 // logrus.WithFields().
 func TestLogEntryWithNonErrorTypeNotReceived(t *testing.T) {
 	log := logrus.New()
-	ts := startAirbrakeServer(t)
-	defer ts.Close()
-
-	hook := NewHook(ts.URL, testAPIKey, "production")
+	hook := newTestHook()
 	log.Hooks.Add(hook)
 
 	log.WithFields(logrus.Fields{
@@ -118,16 +103,34 @@ func TestLogEntryWithNonErrorTypeNotReceived(t *testing.T) {
 	}
 }
 
-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()
+// Returns a new airbrakeHook with the test server proxied
+func newTestHook() *airbrakeHook {
+	// Make a http.Client with the transport
+	httpClient := &http.Client{Transport: &FakeRoundTripper{}}
 
-		noticeError <- notice.Error
-	}))
+	hook := NewHook(123, testAPIKey, "production")
+	hook.Airbrake.Client = httpClient
+	return hook
+}
+
+// gobrake API doesn't allow to override endpoint, we need a http.Roundtripper
+type FakeRoundTripper struct {
+}
 
-	return ts
+func (rt *FakeRoundTripper) RoundTrip(r *http.Request) (*http.Response, error) {
+	b, err := ioutil.ReadAll(r.Body)
+	if err != nil {
+		panic(err)
+	}
+
+	notice := &gobrake.Notice{}
+	err = json.Unmarshal(b, notice)
+	noticeError <- notice.Errors[0]
+
+	res := &http.Response{
+		StatusCode: http.StatusCreated,
+		Body:       ioutil.NopCloser(strings.NewReader("")),
+		Header:     make(http.Header),
+	}
+	return res, nil
 }

text_formatter.go

@@ -18,8 +18,9 @@ const (
 )
 
 var (
-	baseTimestamp time.Time
-	isTerminal    bool
+	baseTimestamp          time.Time
+	isTerminal             bool
+	defaultTimestampFormat = time.RFC3339
 )
 
 func init() {
@@ -46,6 +47,9 @@ type TextFormatter struct {
 	// the time passed since beginning of execution.
 	FullTimestamp bool
 
+	// Timestamp format to use for display, if 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 +72,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 +110,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]

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.