diff --git a/go.mod b/go.mod index a990d6d7..ee516e8b 100644 --- a/go.mod +++ b/go.mod @@ -12,6 +12,7 @@ require ( github.com/mitchellh/go-homedir v1.1.0 github.com/opentracing/basictracer-go v1.0.0 github.com/opentracing/opentracing-go v1.1.0 + github.com/sirupsen/logrus v1.5.0 github.com/stretchr/testify v1.5.1 github.com/undefinedlabs/go-mpatch v0.0.0-20200326085307-1a86426f42a6 github.com/vmihailenco/msgpack v4.0.4+incompatible diff --git a/go.sum b/go.sum index e82076c1..d55e69a2 100644 --- a/go.sum +++ b/go.sum @@ -26,6 +26,8 @@ github.com/google/uuid v1.1.1 h1:Gkbcsh/GbpXz7lPftLA3P6TYMwjCLYm83jiFQZF/3gY= github.com/google/uuid v1.1.1/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= github.com/kisielk/errcheck v1.2.0/go.mod h1:/BMXB+zMLi60iA8Vv6Ksmxu/1UDYcXs4uQLJ+jE2L00= github.com/kisielk/gotool v1.0.0/go.mod h1:XhKaO+MFFWcvkIS/tQcRk01m1F5IRFswLeQ+oQHNcck= +github.com/konsorten/go-windows-terminal-sequences v1.0.1 h1:mweAR1A6xJ3oS2pRaGiHgQ4OO8tzTaLawm8vnODuwDk= +github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ= github.com/kr/pretty v0.2.0 h1:s5hAObm+yFO5uHYt5dYjxi2rXrsnmRpJx4OYvIWUaQs= github.com/kr/pretty v0.2.0/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI= github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= @@ -40,7 +42,10 @@ github.com/opentracing/opentracing-go v1.1.0/go.mod h1:UkNAQd3GIcIGf0SeVgPpRdFSt github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= +github.com/sirupsen/logrus v1.5.0 h1:1N5EYkVAPEywqZRJd7cwnRtCb6xJx7NH3T3WUTF980Q= +github.com/sirupsen/logrus v1.5.0/go.mod h1:+F7Ogzej0PZc/94MaYx/nvG9jOFMD2osvC3s+Squfpo= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.5.1 h1:nOGnQDM7FYENwehXlg/kFVnos3rEvtKTjRvOWSzb6H4= github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA= github.com/undefinedlabs/go-mpatch v0.0.0-20200122175732-0044123dbb98 h1:Z/megzdoMbuZ0H/oLmfTw92PAEfyTi1DkvAr8AUzFgw= @@ -67,6 +72,7 @@ golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sys v0.0.0-20180830151530-49385e6e1522/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190422165155-953cdadca894/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200302150141-5c8b2ff67527 h1:uYVVQ9WP/Ds2ROhcaGPeIdVq0RIXVLwsHlnvJ+cT1So= golang.org/x/sys v0.0.0-20200302150141-5c8b2ff67527/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= diff --git a/instrumentation/logrus/hook.go b/instrumentation/logrus/hook.go new file mode 100644 index 00000000..6c8f5db2 --- /dev/null +++ b/instrumentation/logrus/hook.go @@ -0,0 +1,101 @@ +package logrus + +import ( + "fmt" + "path/filepath" + + "github.com/opentracing/opentracing-go" + otLog "github.com/opentracing/opentracing-go/log" + + log "github.com/sirupsen/logrus" + + "go.undefinedlabs.com/scopeagent/tags" + "go.undefinedlabs.com/scopeagent/tracer" +) + +type ( + ScopeHook struct { + LogLevels []log.Level + } +) + +var scopeHook = &ScopeHook{} + +// Adds an scope hook in the logger if is not already added. +func AddScopeHook(logger *log.Logger) { + // We check first if the logger already contains a ScopeHook instance + for _, hooks := range logger.Hooks { + for _, hook := range hooks { + if _, ok := hook.(*ScopeHook); ok { + return + } + } + } + logger.AddHook(scopeHook) +} + +// Fire will be called when some logging function is called with current hook +// It will format log entry to string and write it to appropriate writer +func (hook *ScopeHook) Fire(entry *log.Entry) error { + if entry.Context == nil { + return nil + } + + // If context is found, we try to find the a span from the context and write the logs + if span := opentracing.SpanFromContext(entry.Context); span != nil { + + logLevel := tags.LogLevel_VERBOSE + if entry.Level == log.PanicLevel || entry.Level == log.FatalLevel || entry.Level == log.ErrorLevel { + logLevel = tags.LogLevel_ERROR + } else if entry.Level == log.WarnLevel { + logLevel = tags.LogLevel_WARNING + } else if entry.Level == log.InfoLevel { + logLevel = tags.LogLevel_INFO + } else if entry.Level == log.DebugLevel { + logLevel = tags.LogLevel_DEBUG + } else if entry.Level == log.TraceLevel { + logLevel = tags.LogLevel_VERBOSE + } + + fields := []otLog.Field{ + otLog.String(tags.EventType, tags.LogEvent), + otLog.String(tags.LogEventLevel, logLevel), + otLog.String("log.logger", "logrus"), + otLog.String("log.level", entry.Level.String()), + otLog.String(tags.EventMessage, entry.Message), + } + + if entry.Caller != nil && entry.Caller.File != "" && entry.Caller.Line != 0 { + fields = append(fields, otLog.String(tags.EventSource, fmt.Sprintf("%s:%d", filepath.Clean(entry.Caller.File), entry.Caller.Line))) + } + + if entry.Data != nil { + for k, v := range entry.Data { + fields = append(fields, otLog.Object(k, v)) + } + } + + if ownSpan, ok := span.(tracer.Span); ok { + ownSpan.LogFieldsWithTimestamp(entry.Time, fields...) + } else { + span.LogFields(fields...) + } + } + return nil +} + +// Levels define on which log levels this hook would trigger +func (hook *ScopeHook) Levels() []log.Level { + if hook.LogLevels == nil { + hook.LogLevels = []log.Level{ + log.PanicLevel, + log.FatalLevel, + log.ErrorLevel, + log.WarnLevel, + log.InfoLevel, + log.DebugLevel, + log.TraceLevel, + } + } + return hook.LogLevels +} diff --git a/instrumentation/logrus/hook_test.go b/instrumentation/logrus/hook_test.go new file mode 100644 index 00000000..fc742a05 --- /dev/null +++ b/instrumentation/logrus/hook_test.go @@ -0,0 +1,35 @@ +package logrus + +import ( + "github.com/sirupsen/logrus" + "os" + "testing" + + "go.undefinedlabs.com/scopeagent" + "go.undefinedlabs.com/scopeagent/agent" + "go.undefinedlabs.com/scopeagent/tracer" +) + +var r *tracer.InMemorySpanRecorder + +func TestMain(m *testing.M) { + // Test tracer + r = tracer.NewInMemoryRecorder() + os.Exit(scopeagent.Run(m, agent.WithRecorders(r))) +} + +func TestLogrus(t *testing.T) { + ctx := scopeagent.GetContextFromTest(t) + r.Reset() + + logger := logrus.New() + logger.SetLevel(logrus.TraceLevel) + logger.SetReportCaller(true) + AddScopeHook(logger) + + logger.WithContext(ctx).WithField("Data", "Value").Error("Error message") + logger.WithContext(ctx).WithField("Data", "Value").Warn("Warning message") + logger.WithContext(ctx).WithField("Data", "Value").Info("Info message") + logger.WithContext(ctx).WithField("Data", "Value").Debug("Debug message") + logger.WithContext(ctx).WithField("Data", "Value").Trace("Trace message") +} diff --git a/tracer/span.go b/tracer/span.go index 1fd3879d..29e81726 100644 --- a/tracer/span.go +++ b/tracer/span.go @@ -25,6 +25,9 @@ type Span interface { // Sets the start time SetStart(start time.Time) opentracing.Span + + // Log fields with timestamp + LogFieldsWithTimestamp(t time.Time, fields ...log.Field) } // Implements the `Span` interface. Created via tracerImpl (see @@ -143,6 +146,23 @@ func (s *spanImpl) LogFields(fields ...log.Field) { s.appendLog(lr) } +func (s *spanImpl) LogFieldsWithTimestamp(t time.Time, fields ...log.Field) { + lr := opentracing.LogRecord{ + Timestamp: t, + Fields: fields, + } + defer s.onLogFields(lr) + s.Lock() + defer s.Unlock() + if s.trim() || s.tracer.options.DropAllLogs { + return + } + if lr.Timestamp.IsZero() { + lr.Timestamp = time.Now() + } + s.appendLog(lr) +} + func (s *spanImpl) LogEvent(event string) { s.Log(opentracing.LogData{ Event: event,