diff --git a/client.go b/client.go index 0a5e1e8..b5104ed 100644 --- a/client.go +++ b/client.go @@ -178,7 +178,7 @@ func (packet *Packet) Init(project string) error { } if packet.EventID == "" { var err error - packet.EventID, err = uuid() + packet.EventID, err = createUUID() if err != nil { return err } @@ -219,7 +219,7 @@ func (packet *Packet) AddTags(tags map[string]string) { } } -func uuid() (string, error) { +func createUUID() (string, error) { id := make([]byte, 16) _, err := io.ReadFull(rand.Reader, id) if err != nil { diff --git a/logrus.go b/logrus.go new file mode 100644 index 0000000..c2606b9 --- /dev/null +++ b/logrus.go @@ -0,0 +1,240 @@ +package raven + +import ( + "encoding/json" + "fmt" + "net/http" + "time" + + "github.com/Sirupsen/logrus" +) + +var ( + severityMap = map[logrus.Level]Severity{ + logrus.DebugLevel: DEBUG, + logrus.InfoLevel: INFO, + logrus.WarnLevel: WARNING, + logrus.ErrorLevel: ERROR, + logrus.FatalLevel: FATAL, + logrus.PanicLevel: FATAL, + } +) + +func getEventID(d logrus.Fields) (string, bool) { + eventID, ok := d["event_id"].(string) + + if !ok { + return "", false + } + + //verify eventID is 32 characters hexadecimal string (UUID4) + uuid := parseUUID(eventID) + + if uuid == nil { + return "", false + } + + return uuid.noDashString(), true +} + +func getUserContext(d logrus.Fields) (*User, bool) { + if v, ok := d["user"]; ok { + switch val := v.(type) { + case *User: + return val, true + + case User: + return &val, true + } + } + + username, _ := d["user_name"].(string) + email, _ := d["user_email"].(string) + id, _ := d["user_id"].(string) + ip, _ := d["user_ip"].(string) + + if username == "" && email == "" && id == "" && ip == "" { + return nil, false + } + + return &User{ + ID: id, + Username: username, + Email: email, + IP: ip, + }, true +} + +func getAndDel(d logrus.Fields, key string) (string, bool) { + if value, ok := d[key].(string); ok { + delete(d, key) + return value, true + } else { + return "", false + } +} + +func getAndDelError(d logrus.Fields, key string) (error, bool) { + if value, ok := d[key].(error); ok { + delete(d, key) + return value, true + } else { + return nil, false + } +} + +func getAndDelRequest(d logrus.Fields, key string) (*http.Request, bool) { + if value, ok := d[key].(*http.Request); ok { + delete(d, key) + return value, true + } else { + return nil, false + } +} + +// SentryHook delivers logs to a sentry server. +type SentryHook struct { + // Timeout sets the time to wait for a delivery error from the sentry server. + // If this is set to zero the server will not wait for any response and will + // consider the message correctly sent + Timeout time.Duration + StacktraceConfiguration StackTraceConfiguration + + client *Client + levels []logrus.Level +} + +// StackTraceConfiguration allows for configuring stacktraces +type StackTraceConfiguration struct { + // whether stacktraces should be enabled + Enable bool + // the level at which to start capturing stacktraces + Level logrus.Level + // how many stack frames to skip before stacktrace starts recording + Skip int + // the number of lines to include around a stack frame for context + Context int + // the prefixes that will be matched against the stack frame. + // if the stack frame's package matches one of these prefixes + // sentry will identify the stack frame as "in_app" + InAppPrefixes []string +} + +// NewSentryHook creates a hook to be added to an instance of logger +// and initializes the raven client. +// This method sets the timeout to 100 milliseconds. +func NewSentryHook(DSN string, levels []logrus.Level) (*SentryHook, error) { + client, err := New(DSN) + if err != nil { + return nil, err + } + return NewWithClientSentryHook(client, levels) +} + +// NewWithTagsSentryHook creates a hook with tags to be added to an instance +// of logger and initializes the raven client. This method sets the timeout to +// 100 milliseconds. +func NewWithTagsSentryHook(DSN string, tags map[string]string, levels []logrus.Level) (*SentryHook, error) { + client, err := NewWithTags(DSN, tags) + if err != nil { + return nil, err + } + return NewWithClientSentryHook(client, levels) +} + +// NewWithClientSentryHook creates a hook using an initialized raven client. +// This method sets the timeout to 100 milliseconds. +func NewWithClientSentryHook(client *Client, levels []logrus.Level) (*SentryHook, error) { + return &SentryHook{ + Timeout: 100 * time.Millisecond, + StacktraceConfiguration: StackTraceConfiguration{ + Enable: false, + Level: logrus.ErrorLevel, + Skip: 5, + Context: 0, + InAppPrefixes: nil, + }, + client: client, + levels: levels, + }, nil +} + +func formatExtraData(fields logrus.Fields) (ret map[string]interface{}) { + ret = make(map[string]interface{}, len(fields)) + for key, value := range fields { + switch value := value.(type) { + case json.Marshaler: + ret[key] = value + case error: + ret[key] = value.Error() + case fmt.Stringer: + ret[key] = value.String() + default: + ret[key] = value + } + } + return +} + +// Called when an event should be sent to sentry +// Special fields that sentry uses to give more information to the server +// are extracted from entry.Data (if they are found) +// These fields are: error, logger, server_name and http_request +func (hook *SentryHook) Fire(entry *logrus.Entry) error { + packet := &Packet{ + Message: entry.Message, + Timestamp: Timestamp(entry.Time), + Level: severityMap[entry.Level], + Platform: "go", + } + + d := entry.Data + + if logger, ok := getAndDel(d, "logger"); ok { + packet.Logger = logger + } + if serverName, ok := getAndDel(d, "server_name"); ok { + packet.ServerName = serverName + } + if req, ok := getAndDelRequest(d, "http_request"); ok { + packet.Interfaces = append(packet.Interfaces, NewHttp(req)) + } + if user, ok := getUserContext(d); ok { + packet.Interfaces = append(packet.Interfaces, user) + } + if eventID, ok := getEventID(d); ok { + packet.EventID = eventID + } + + stConfig := &hook.StacktraceConfiguration + if stConfig.Enable && entry.Level <= stConfig.Level { + currentStacktrace := NewStacktrace(stConfig.Skip, stConfig.Context, stConfig.InAppPrefixes) + if err, ok := getAndDelError(d, logrus.ErrorKey); ok { + exc := NewException(err, currentStacktrace) + packet.Interfaces = append(packet.Interfaces, exc) + packet.Culprit = err.Error() + } else { + packet.Interfaces = append(packet.Interfaces, currentStacktrace) + } + } + + packet.Extra = formatExtraData(d) + + _, errCh := hook.client.Capture(packet, nil) + timeout := hook.Timeout + if timeout != 0 { + timeoutCh := time.After(timeout) + select { + case err := <-errCh: + return err + case <-timeoutCh: + return fmt.Errorf("no response from sentry server in %s", timeout) + } + } + return nil +} + +// Levels returns the available logging levels. +func (hook *SentryHook) Levels() []logrus.Level { + return hook.levels +} diff --git a/logrus_test.go b/logrus_test.go new file mode 100644 index 0000000..eb14bf0 --- /dev/null +++ b/logrus_test.go @@ -0,0 +1,259 @@ +package raven + +import ( + "compress/zlib" + "encoding/base64" + "encoding/json" + "errors" + "fmt" + "io" + "io/ioutil" + "net/http" + "net/http/httptest" + "reflect" + "strings" + "testing" + "time" + + "github.com/Sirupsen/logrus" +) + +const ( + message = "error message" + server_name = "testserver.internal" + logger_name = "test.logger" +) + +func getTestLogger() *logrus.Logger { + l := logrus.New() + l.Out = ioutil.Discard + return l +} + +// Packet does not have a json directive for deserializing stacktrace +// so need to explicitly construct one for purpose of test +type resultPacket struct { + Packet + Stacktrace Stacktrace `json:"stacktrace"` +} + +func WithTestDSN(t *testing.T, tf func(string, <-chan *resultPacket)) { + pch := make(chan *resultPacket, 1) + s := httptest.NewServer(http.HandlerFunc(func(rw http.ResponseWriter, req *http.Request) { + defer req.Body.Close() + contentType := req.Header.Get("Content-Type") + var bodyReader io.Reader = req.Body + // underlying client will compress and encode payload above certain size + if contentType == "application/octet-stream" { + bodyReader = base64.NewDecoder(base64.StdEncoding, bodyReader) + bodyReader, _ = zlib.NewReader(bodyReader) + } + + d := json.NewDecoder(bodyReader) + p := &resultPacket{} + err := d.Decode(p) + if err != nil { + t.Fatal(err.Error()) + } + + pch <- p + })) + defer s.Close() + + fragments := strings.SplitN(s.URL, "://", 2) + dsn := fmt.Sprintf( + "%s://public:secret@%s/sentry/project-id", + fragments[0], + fragments[1], + ) + tf(dsn, pch) +} + +func TestSpecialFields(t *testing.T) { + WithTestDSN(t, func(dsn string, pch <-chan *resultPacket) { + logger := getTestLogger() + + hook, err := NewSentryHook(dsn, []logrus.Level{ + logrus.ErrorLevel, + }) + + if err != nil { + t.Fatal(err.Error()) + } + logger.Hooks.Add(hook) + + req, _ := http.NewRequest("GET", "url", nil) + logger.WithFields(logrus.Fields{ + "server_name": server_name, + "logger": logger_name, + "http_request": req, + }).Error(message) + + packet := <-pch + if packet.Logger != logger_name { + t.Errorf("logger should have been %s, was %s", logger_name, packet.Logger) + } + + if packet.ServerName != server_name { + t.Errorf("server_name should have been %s, was %s", server_name, packet.ServerName) + } + }) +} + +func TestSentryHandler(t *testing.T) { + WithTestDSN(t, func(dsn string, pch <-chan *resultPacket) { + logger := getTestLogger() + hook, err := NewSentryHook(dsn, []logrus.Level{ + logrus.ErrorLevel, + }) + if err != nil { + t.Fatal(err.Error()) + } + logger.Hooks.Add(hook) + + logger.Error(message) + packet := <-pch + if packet.Message != message { + t.Errorf("message should have been %s, was %s", message, packet.Message) + } + }) +} + +func TestSentryWithClient(t *testing.T) { + WithTestDSN(t, func(dsn string, pch <-chan *resultPacket) { + logger := getTestLogger() + + client, _ := New(dsn) + + hook, err := NewWithClientSentryHook(client, []logrus.Level{ + logrus.ErrorLevel, + }) + if err != nil { + t.Fatal(err.Error()) + } + logger.Hooks.Add(hook) + + logger.Error(message) + packet := <-pch + if packet.Message != message { + t.Errorf("message should have been %s, was %s", message, packet.Message) + } + }) +} + +func TestSentryTags(t *testing.T) { + WithTestDSN(t, func(dsn string, pch <-chan *resultPacket) { + logger := getTestLogger() + tags := map[string]string{ + "site": "test", + } + levels := []logrus.Level{ + logrus.ErrorLevel, + } + + hook, err := NewWithTagsSentryHook(dsn, tags, levels) + if err != nil { + t.Fatal(err.Error()) + } + + logger.Hooks.Add(hook) + + logger.Error(message) + packet := <-pch + expected := Tags{ + Tag{ + Key: "site", + Value: "test", + }, + } + if !reflect.DeepEqual(packet.Tags, expected) { + t.Errorf("message should have been %s, was %s", message, packet.Message) + } + }) +} + +func TestSentryStacktrace(t *testing.T) { + WithTestDSN(t, func(dsn string, pch <-chan *resultPacket) { + logger := getTestLogger() + hook, err := NewSentryHook(dsn, []logrus.Level{ + logrus.ErrorLevel, + logrus.InfoLevel, + }) + if err != nil { + t.Fatal(err.Error()) + } + logger.Hooks.Add(hook) + + logger.Error(message) + packet := <-pch + stacktraceSize := len(packet.Stacktrace.Frames) + if stacktraceSize != 0 { + t.Error("Stacktrace should be empty as it is not enabled") + } + + hook.StacktraceConfiguration.Enable = true + + logger.Error(message) // this is the call that the last frame of stacktrace should capture + expectedLineno := 196 //this should be the line number of the previous line + + packet = <-pch + stacktraceSize = len(packet.Stacktrace.Frames) + if stacktraceSize == 0 { + t.Error("Stacktrace should not be empty") + } + lastFrame := packet.Stacktrace.Frames[stacktraceSize-1] + expectedSuffix := "raven-go/logrus_test.go" + if !strings.HasSuffix(lastFrame.Filename, expectedSuffix) { + t.Errorf("File name should have ended with %s, was %s", expectedSuffix, lastFrame.Filename) + } + if lastFrame.Lineno != expectedLineno { + t.Errorf("Line number should have been %d, was %d", expectedLineno, lastFrame.Lineno) + } + if lastFrame.InApp { + t.Error("Frame should not be identified as in_app without prefixes") + } + + hook.StacktraceConfiguration.InAppPrefixes = []string{"github.com/Sirupsen/logrus"} + hook.StacktraceConfiguration.Context = 2 + hook.StacktraceConfiguration.Skip = 2 + + logger.Error(message) + packet = <-pch + stacktraceSize = len(packet.Stacktrace.Frames) + if stacktraceSize == 0 { + t.Error("Stacktrace should not be empty") + } + lastFrame = packet.Stacktrace.Frames[stacktraceSize-1] + expectedFilename := "github.com/Sirupsen/logrus/entry.go" + if lastFrame.Filename != expectedFilename { + t.Errorf("File name should have been %s, was %s", expectedFilename, lastFrame.Filename) + } + if !lastFrame.InApp { + t.Error("Frame should be identified as in_app") + } + }) +} + +func TestFormatExtraData(t *testing.T) { + fields := logrus.Fields{ + "time_stamp": time.Now(), // implements JSON marshaler + "time_duration": time.Hour, // implements .String() + "err": errors.New("this is a test error"), + "order": 13, + } + + formatted := formatExtraData(fields) + + if _, ok := formatted["time_stamp"].(time.Time); !ok { + t.Error("json.Marshaler field shound't change type") + } + if _, ok := formatted["time_duration"].(string); !ok { + t.Error("fmt.Stringer field should be converted to string") + } + if _, ok := formatted["err"].(string); !ok { + t.Error("error field should be converted to string") + } + if _, ok := formatted["order"].(int); !ok { + t.Error("int field shound't change type") + } +} diff --git a/utils.go b/utils.go new file mode 100644 index 0000000..54132e1 --- /dev/null +++ b/utils.go @@ -0,0 +1,135 @@ +package raven + +import ( + "fmt" + "strings" +) + +/* +Copyright (c) 2009,2014 Google Inc. All rights reserved. + +Redistribution and use in source and binary forms, with or without +modification, are permitted provided that the following conditions are +met: + + * Redistributions of source code must retain the above copyright +notice, this list of conditions and the following disclaimer. + * Redistributions in binary form must reproduce the above +copyright notice, this list of conditions and the following disclaimer +in the documentation and/or other materials provided with the +distribution. + * Neither the name of Google Inc. nor the names of its +contributors may be used to endorse or promote products derived from +this software without specific prior written permission. + +THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS +"AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT +LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR +A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT +OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, +SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT +LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, +DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY +THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT +(INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE +OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. +*/ + +// A UUID is a 128 bit (16 byte) Universal Unique IDentifier as defined in RFC +// 4122. +type uuid []byte + +// parseUUID decodes s into a UUID or returns nil. Both the UUID form of +// xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx and +// xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx and +// urn:uuid:xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx are decoded. +func parseUUID(s string) uuid { + //If it is in no dash format "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx" + if len(s) == 32 { + uuid := make([]byte, 16) + for i, x := range []int{ + 0, 2, 4, 6, 8, 10, + 12, 14, 16, 18, 20, + 22, 24, 26, 28, 30} { + if v, ok := xtob(s[x:]); !ok { + return nil + } else { + uuid[i] = v + } + } + return uuid + } + + if len(s) == 36+9 { + if strings.ToLower(s[:9]) != "urn:uuid:" { + return nil + } + s = s[9:] + } else if len(s) != 36 { + return nil + } + if s[8] != '-' || s[13] != '-' || s[18] != '-' || s[23] != '-' { + return nil + } + uuid := make([]byte, 16) + for i, x := range []int{ + 0, 2, 4, 6, + 9, 11, + 14, 16, + 19, 21, + 24, 26, 28, 30, 32, 34} { + if v, ok := xtob(s[x:]); !ok { + return nil + } else { + uuid[i] = v + } + } + return uuid +} + +// String returns the string form of uuid, xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx +// , or "" if uuid is invalid. +func (uuid uuid) string() string { + if uuid == nil || len(uuid) != 16 { + return "" + } + b := []byte(uuid) + return fmt.Sprintf("%08x-%04x-%04x-%04x-%012x", + b[:4], b[4:6], b[6:8], b[8:10], b[10:]) +} + +func (uuid uuid) noDashString() string { + if uuid == nil || len(uuid) != 16 { + return "" + } + b := []byte(uuid) + return fmt.Sprintf("%08x%04x%04x%04x%012x", + b[:4], b[4:6], b[6:8], b[8:10], b[10:]) +} + +// xvalues returns the value of a byte as a hexadecimal digit or 255. +var xvalues = []byte{ + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 255, 255, 255, 255, 255, 255, + 255, 10, 11, 12, 13, 14, 15, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 10, 11, 12, 13, 14, 15, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, + 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, 255, +} + +// xtob converts the the first two hex bytes of x into a byte. +func xtob(x string) (byte, bool) { + b1 := xvalues[x[0]] + b2 := xvalues[x[1]] + return (b1 << 4) | b2, b1 != 255 && b2 != 255 +}