diff --git a/.github/workflows/golangci-lint.yaml b/.github/workflows/golangci-lint.yaml new file mode 100644 index 0000000..6c2d8eb --- /dev/null +++ b/.github/workflows/golangci-lint.yaml @@ -0,0 +1,32 @@ +name: golangci-lint +on: + push: + branches: + - master + pull_request: + branches: + - master +env: + GOPRIVATE: "github.com/Khan" + GOFLAGS: "-trimpath" + GO_VERSION: 1.18 +jobs: + golangci: + name: Linter + runs-on: ubuntu-latest + steps: + - name: Install Go + uses: actions/setup-go@v2 + with: + # stable: 'false' # Keep this line to be able to use rc and beta version of Go (ex: 1.18.0-rc1). + go-version: ${{ env.GO_VERSION }} + - uses: actions/checkout@v2 + - name: lint + uses: golangci/golangci-lint-action@v3.1.0 + with: + version: latest + # skip cache because of flaky behaviors + skip-build-cache: true + skip-pkg-cache: true + args: --timeout 5m --issues-exit-code=0 + # only-new-issues: true #show only new issues if it's a pull request. options working-directory and only-new-issues are incompatible \ No newline at end of file diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml new file mode 100644 index 0000000..649401e --- /dev/null +++ b/.github/workflows/test.yml @@ -0,0 +1,28 @@ +name: Test +on: + push: + branches: + - master + pull_request: + branches: + - master +env: + GOPRIVATE: "github.com/Khan" + GOFLAGS: "-trimpath" + GO_VERSION: 1.18 +jobs: + test: +# runs-on: [self-hosted, linux, x64] + runs-on: ubuntu-latest + timeout-minutes: 40 + steps: + - name: Install Go + uses: actions/setup-go@v2 + with: + go-version: ${{ env.GO_VERSION }} + - name: Checkout code + uses: actions/checkout@v2 + - name: Test + run: |- + echo "starting go tests without race" + go test ./... -timeout 5m -v -trimpath \ No newline at end of file diff --git a/README.md b/README.md index 587fca8..ddae773 100644 --- a/README.md +++ b/README.md @@ -1,8 +1,8 @@ # logrus-stackdriver-formatter -[![Go Report Card](https://goreportcard.com/badge/github.com/StevenACoffman/logrus-stackdriver-formatter)](https://goreportcard.com/report/github.com/StevenACoffman/logrus-stackdriver-formatter) -[![GoDoc](https://img.shields.io/badge/godoc-reference-blue.svg?style=flat)](https://godoc.org/github.com/StevenACoffman/logrus-stackdriver-formatter) -[![License MIT](https://img.shields.io/badge/license-MIT-lightgrey.svg?style=flat)](https://github.com/StevenACoffman/logrus-stackdriver-formatter#license) +[![Go Report Card](https://goreportcard.com/badge/github.com/Mattel/logrus-stackdriver-formatter)](https://goreportcard.com/report/github.com/Mattel/logrus-stackdriver-formatter) +[![GoDoc](https://img.shields.io/badge/godoc-reference-blue.svg?style=flat)](https://godoc.org/github.com/Mattel/logrus-stackdriver-formatter) +[![License MIT](https://img.shields.io/badge/license-MIT-lightgrey.svg?style=flat)](https://github.com/Mattel/logrus-stackdriver-formatter#license) Logrus-stackdriver-formatter provides: + [logrus](https://github.com/sirupsen/logrus) formatter for Stackdriver. @@ -23,7 +23,7 @@ package main import ( -stackdriver "github.com/StevenACoffman/logrus-stackdriver-formatter" +stackdriver "github.com/Mattel/logrus-stackdriver-formatter" "github.com/sirupsen/logrus" ) @@ -52,7 +52,7 @@ Here's a sample entry (prettified) from the example: "severity": "ERROR", "context": { "reportLocation": { - "file": "github.com/StevenACoffman/logrus-stackdriver-formatter/example_test.go", + "file": "github.com/Mattel/logrus-stackdriver-formatter/example_test.go", "line": 21, "function": "ExampleLogError" } @@ -99,7 +99,7 @@ and log-structured data streams. ```go import ( "os" - logadapter "github.com/StevenACoffman/logrus-stackdriver-formatter" + logadapter "github.com/Mattel/logrus-stackdriver-formatter" kitlog "github.com/go-kit/kit/log" ) @@ -118,7 +118,7 @@ func main() { ```go import ( "os" - logadapter "github.com/StevenACoffman/logrus-stackdriver-formatter" + logadapter "github.com/Mattel/logrus-stackdriver-formatter" kitlog "github.com/go-kit/kit/log" ) diff --git a/example/example_test.go b/example/example_test.go index 106fe85..e175257 100644 --- a/example/example_test.go +++ b/example/example_test.go @@ -1,36 +1,108 @@ package logadapterexample import ( - "os" + "bufio" + "bytes" + "encoding/json" + "fmt" "strconv" + "strings" + + "github.com/gofrs/uuid" + "go.opentelemetry.io/otel/trace" stackdriver "github.com/Mattel/logrus-stackdriver-formatter" "github.com/sirupsen/logrus" ) +var ( + TraceFlags = trace.FlagsSampled + TraceID = uuid.Must(uuid.FromString("105445aa7843bc8bf206b12000100000")) + SpanID = [8]byte{0, 0, 0, 0, 0, 0, 0, 1} + SpanContext = trace.SpanContext{}.WithSpanID(SpanID). + WithTraceID(trace.TraceID(TraceID)). + WithTraceFlags(TraceFlags) +) + func ExampleWithError() { logger := logrus.New() - logger.Out = os.Stdout + var b bytes.Buffer + foo := bufio.NewWriter(&b) + logger.Out = foo logger.Formatter = stackdriver.NewFormatter( stackdriver.WithService("test-service"), stackdriver.WithVersion("v0.1.0"), stackdriver.WithSkipTimestamp(), + stackdriver.WithGlobalTraceID(TraceID), ) - logger.Info("application up and running") + logger.WithField("span_context", SpanContext).Info("application up and running") _, err := strconv.ParseInt("text", 10, 64) if err != nil { - logger.WithError(err).WithField("trace", "1").Errorln("unable to parse integer") + logger.WithField("span_context", SpanContext).WithError(err). + Errorln("unable to parse integer") } + foo.Flush() + + fmt.Println(PrettyString(b.String())) // Output: - // {"message":"application up and running","severity":"INFO","context":{}} - // {"serviceContext":{"service":"test-service","version":"v0.1.0"},"message": - // "unable to parse integer\nstrconv.ParseInt: - // parsing \"text\": invalid syntax","severity":"ERROR","context": - // {"reportLocation": - // {"file":"testing/example_test.go","line":121,"function":"runExample"}}, - // "sourceLocation": - // {"file":"testing/example_test.go","line":121,"function":"runExample"}} + // { + // "logName": "projects//logs/test-service", + // "message": "application up and running", + // "severity": "INFO", + // "context": {}, + // "logging.googleapis.com/sourceLocation": { + // "file": "testing/run_example.go", + // "line": 63, + // "function": "runExample" + // }, + // "logging.googleapis.com/trace": "projects//traces/105445aa7843bc8bf206b12000100000", + // "logging.googleapis.com/spanId": "0000000000000001", + // "logging.googleapis.com/trace_sampled": true + // } + // { + // "@type": "type.googleapis.com/google.devtools.clouderrorreporting.v1beta1.ReportedErrorEvent", + // "logName": "projects//logs/test-service", + // "serviceContext": { + // "service": "test-service", + // "version": "v0.1.0" + // }, + // "message": "unable to parse integer\nstrconv.ParseInt: parsing \"text\": invalid syntax", + // "severity": "ERROR", + // "context": { + // "data": { + // "error": "strconv.ParseInt: parsing \"text\": invalid syntax" + // }, + // "reportLocation": { + // "filePath": "testing/run_example.go", + // "lineNumber": 63, + // "functionName": "runExample" + // } + // }, + // "logging.googleapis.com/sourceLocation": { + // "file": "testing/run_example.go", + // "line": 63, + // "function": "runExample" + // }, + // "logging.googleapis.com/trace": "projects//traces/105445aa7843bc8bf206b12000100000", + // "logging.googleapis.com/spanId": "0000000000000001", + // "logging.googleapis.com/trace_sampled": true + // } +} + +func PrettyString(str string) string { + var prettyJSON bytes.Buffer + if err := json.Indent(&prettyJSON, []byte(str), "", " "); err != nil { + if strings.Contains(str, "\n") { + var pieces []string + for _, split := range strings.Split(str, "\n") { + pieces = append(pieces, PrettyString(split)) + } + return strings.Join(pieces, "\n") + } + return str + } + return prettyJSON.String() } diff --git a/formatter.go b/formatter.go index 8aa2c9a..4551a49 100644 --- a/formatter.go +++ b/formatter.go @@ -323,7 +323,8 @@ func (f *Formatter) ToEntry(e *logrus.Entry) (Entry, error) { // @type as ReportedErrorEvent if all required fields may be provided // https://cloud.google.com/error-reporting/docs/formatting-error-messages#json_representation - if len(message) > 0 && ee.ServiceContext.Service != "" && (ee.StackTrace != "" || ee.SourceLocation != nil) { + if len(message) > 0 && ee.ServiceContext.Service != "" && + (ee.StackTrace != "" || ee.SourceLocation != nil) { ee.Type = reportedErrorEventType } } @@ -347,9 +348,10 @@ func (f *Formatter) ToEntry(e *logrus.Entry) (Entry, error) { delete(ee.Context.Data, "httpRequest") } - // Promote the httpRequest details to parent entry so logs may be presented with HTTP request details - // Only do this when the logging middleware provides special instructions in log entry context to do so, - // as the resulting log message summary line is specially formatted to ignore the payload message + // Promote the httpRequest details to parent entry so logs may be presented with HTTP request + // details Only do this when the logging middleware provides special instructions in log entry + // context to do so, as the resulting log message summary line is specially formatted to ignore + // the payload message if req, ok := ee.Context.Data["httpRequest"].(requestDetails); ok { ee.HTTPRequest = req.HTTPRequest delete(ee.Context.Data, "httpRequest") diff --git a/formatter_test.go b/formatter_test.go index 2525993..b042027 100644 --- a/formatter_test.go +++ b/formatter_test.go @@ -4,11 +4,15 @@ import ( "bytes" "encoding/json" "errors" + "runtime" "testing" + "github.com/gofrs/uuid" + logadapter "github.com/Mattel/logrus-stackdriver-formatter" "github.com/sirupsen/logrus" "github.com/stretchr/testify/assert" + "go.opentelemetry.io/otel/trace" ) func TestFormatter(t *testing.T) { @@ -28,8 +32,8 @@ func TestFormatter(t *testing.T) { "https://github.com/Mattel/test.git", "v1.2.3", ), + logadapter.WithGlobalTraceID(TraceID), ) - tt.run(logger) got, err := json.Marshal(tt.out) @@ -41,6 +45,16 @@ func TestFormatter(t *testing.T) { } } +var ( + TraceFlags = trace.FlagsSampled + TraceID = uuid.Must(uuid.FromString("105445aa7843bc8bf206b12000100000")) + SpanID = [8]byte{0, 0, 0, 0, 0, 0, 0, 1} + SpanContext = trace.SpanContext{}.WithSpanID(SpanID). + WithTraceID(trace.TraceID(TraceID)). + WithTraceFlags(TraceFlags) + LineNumber = platformLine() +) + var formatterTests = []struct { run func(*logrus.Logger) out map[string]interface{} @@ -51,7 +65,7 @@ var formatterTests = []struct { run: func(logger *logrus.Logger) { logger. WithField("foo", "bar"). - WithField("trace", "105445aa7843bc8bf206b12000100000/1;o=1"). + WithField("span_context", SpanContext). Info("my log entry") }, out: map[string]interface{}{ @@ -59,18 +73,18 @@ var formatterTests = []struct { "message": "my log entry", "logName": "projects/test-project/logs/test", - "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", - "logging.googleapis.com/spanId": "1", - "logging.googleapis.com/traceSampled": true, + "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", + "logging.googleapis.com/spanId": "0000000000000001", + "logging.googleapis.com/trace_sampled": true, "context": map[string]interface{}{ "data": map[string]interface{}{ "foo": "bar", }, }, - "sourceLocation": map[string]interface{}{ + "logging.googleapis.com/sourceLocation": map[string]interface{}{ "file": "testing/testing.go", "function": "tRunner", - "line": 1194.0, + "line": LineNumber, }, }, }, @@ -79,7 +93,7 @@ var formatterTests = []struct { run: func(logger *logrus.Logger) { logger. WithField("foo", "bar"). - WithField("trace", "105445aa7843bc8bf206b12000100000/1;o=1"). + WithField("span_context", SpanContext). Error("my log entry") }, out: map[string]interface{}{ @@ -88,9 +102,9 @@ var formatterTests = []struct { "message": "my log entry", "logName": "projects/test-project/logs/test", - "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", - "logging.googleapis.com/spanId": "1", - "logging.googleapis.com/traceSampled": true, + "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", + "logging.googleapis.com/spanId": "0000000000000001", + "logging.googleapis.com/trace_sampled": true, "serviceContext": map[string]interface{}{ "service": "test", "version": "0.1", @@ -107,13 +121,13 @@ var formatterTests = []struct { }, "reportLocation": map[string]interface{}{ "filePath": "testing/testing.go", - "lineNumber": 1194.0, + "lineNumber": LineNumber, "functionName": "tRunner", }, }, - "sourceLocation": map[string]interface{}{ + "logging.googleapis.com/sourceLocation": map[string]interface{}{ "file": "testing/testing.go", - "line": 1194.0, + "line": LineNumber, "function": "tRunner", }, }, @@ -123,7 +137,7 @@ var formatterTests = []struct { run: func(logger *logrus.Logger) { logger. WithField("foo", "bar"). - WithField("trace", "105445aa7843bc8bf206b12000100000/1;o=1"). + WithField("span_context", SpanContext). WithError(errors.New("test error")). Error("my log entry") }, @@ -133,9 +147,9 @@ var formatterTests = []struct { "message": "my log entry\ntest error", "logName": "projects/test-project/logs/test", - "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", - "logging.googleapis.com/spanId": "1", - "logging.googleapis.com/traceSampled": true, + "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", + "logging.googleapis.com/spanId": "0000000000000001", + "logging.googleapis.com/trace_sampled": true, "serviceContext": map[string]interface{}{ "service": "test", "version": "0.1", @@ -153,13 +167,13 @@ var formatterTests = []struct { }, "reportLocation": map[string]interface{}{ "filePath": "testing/testing.go", - "lineNumber": 1194.0, + "lineNumber": LineNumber, "functionName": "tRunner", }, }, - "sourceLocation": map[string]interface{}{ + "logging.googleapis.com/sourceLocation": map[string]interface{}{ "file": "testing/testing.go", - "line": 1194.0, + "line": LineNumber, "function": "tRunner", }, }, @@ -169,8 +183,8 @@ var formatterTests = []struct { run: func(logger *logrus.Logger) { logger. WithFields(logrus.Fields{ - "foo": "bar", - "trace": "105445aa7843bc8bf206b12000100000/1;o=1", + "foo": "bar", + "span_context": SpanContext, "httpRequest": map[string]interface{}{ "requestMethod": "GET", }, @@ -183,9 +197,9 @@ var formatterTests = []struct { "message": "my log entry", "logName": "projects/test-project/logs/test", - "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", - "logging.googleapis.com/spanId": "1", - "logging.googleapis.com/traceSampled": true, + "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", + "logging.googleapis.com/spanId": "0000000000000001", + "logging.googleapis.com/trace_sampled": true, "serviceContext": map[string]interface{}{ "service": "test", "version": "0.1", @@ -199,7 +213,7 @@ var formatterTests = []struct { }, "reportLocation": map[string]interface{}{ "filePath": "testing/testing.go", - "lineNumber": 1194.0, + "lineNumber": LineNumber, "functionName": "tRunner", }, "sourceReferences": []map[string]interface{}{ @@ -209,11 +223,22 @@ var formatterTests = []struct { }, }, }, - "sourceLocation": map[string]interface{}{ + "logging.googleapis.com/sourceLocation": map[string]interface{}{ "file": "testing/testing.go", - "line": 1194.0, + "line": LineNumber, "function": "tRunner", }, }, }, } + +func platformLine() float64 { + switch runtime.GOOS { + case "darwin": + return 1193.0 + case "linux": + return 1439.0 + default: // does anyone really use windows? + return 0.0 + } +} diff --git a/logger.go b/logger.go index a5e59f2..213407e 100644 --- a/logger.go +++ b/logger.go @@ -23,12 +23,14 @@ func NewLogrusGoKitLogger(logger logrusLogger) *LogrusGoKitLogger { return &LogrusGoKitLogger{logger} } -const msgKey = "msg" -const messageKey = "message" -const errKey = "err" -const errorKey = "error" -const severityKey = "severity" -const levelKey = "level" +const ( + msgKey = "msg" + messageKey = "message" + errKey = "err" + errorKey = "error" + severityKey = "severity" + levelKey = "level" +) // Log implements the fundamental Logger interface func (l LogrusGoKitLogger) Log(keyvals ...interface{}) error { @@ -43,7 +45,9 @@ func (l LogrusGoKitLogger) Log(keyvals ...interface{}) error { // extractLogElements iterates through the keyvals to form well // structured key:value pairs that Logrus expects. It also checks for keys with // special meaning like "msg" and "level" to format the log entry -func (l LogrusGoKitLogger) extractLogElements(keyVals ...interface{}) (logrus.Fields, logrus.Level, string) { +func (l LogrusGoKitLogger) extractLogElements( + keyVals ...interface{}, +) (logrus.Fields, logrus.Level, string) { msg := "" fields := logrus.Fields{} level := logrus.DebugLevel diff --git a/middleware.go b/middleware.go index 2f0d4e7..ecc7cea 100644 --- a/middleware.go +++ b/middleware.go @@ -44,7 +44,10 @@ type requestDetails struct { // LoggingMiddleware proivdes a request-scoped log entry into context for HTTP // requests, writes request logs in a structured format to stackdriver. -func LoggingMiddleware(log *logrus.Logger, opts ...MiddlewareOption) func(http.Handler) http.Handler { +func LoggingMiddleware( + log *logrus.Logger, + opts ...MiddlewareOption, +) func(http.Handler) http.Handler { o := evaluateMiddlewareOptions(opts) return func(handler http.Handler) http.Handler { @@ -72,7 +75,9 @@ func LoggingMiddleware(log *logrus.Logger, opts ...MiddlewareOption) func(http.H if o.filterHTTP(r) { // log the result - ctxlogrus.Extract(ctx).WithField("httpRequest", requestDetails{request}).Infof("served HTTP %v %v", r.Method, r.URL) + ctxlogrus.Extract(ctx). + WithField("httpRequest", requestDetails{request}). + Infof("served HTTP %v %v", r.Method, r.URL) } }) } @@ -81,7 +86,10 @@ func LoggingMiddleware(log *logrus.Logger, opts ...MiddlewareOption) func(http.H // UnaryLoggingInterceptor provides a request-scoped log entry into context for // Unary gRPC requests, and logs request details on the response. // Logging interceptors should be chained at the very top of the request scope. -func UnaryLoggingInterceptor(logger *logrus.Logger, opts ...MiddlewareOption) grpc.UnaryServerInterceptor { +func UnaryLoggingInterceptor( + logger *logrus.Logger, + opts ...MiddlewareOption, +) grpc.UnaryServerInterceptor { o := evaluateMiddlewareOptions(opts) return loggingInterceptor{logger: logger, middlewareOptions: o}.intercept } @@ -89,7 +97,10 @@ func UnaryLoggingInterceptor(logger *logrus.Logger, opts ...MiddlewareOption) gr // StreamLoggingInterceptor provides a request-scoped log entry into context for // Streaming gRPC requests, and logs request details at the end of the stream. // Logging interceptors should be chained at the very top of the request scope. -func StreamLoggingInterceptor(logger *logrus.Logger, opts ...MiddlewareOption) grpc.StreamServerInterceptor { +func StreamLoggingInterceptor( + logger *logrus.Logger, + opts ...MiddlewareOption, +) grpc.StreamServerInterceptor { o := evaluateMiddlewareOptions(opts) return loggingInterceptor{logger: logger, middlewareOptions: o}.interceptStream } @@ -108,7 +119,12 @@ type GRPCRequest struct { Duration string `json:"duration,omitempty"` } -func (l loggingInterceptor) intercept(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) { +func (l loggingInterceptor) intercept( + ctx context.Context, + req interface{}, + info *grpc.UnaryServerInfo, + handler grpc.UnaryHandler, +) (interface{}, error) { startTime := time.Now() ctx = WithLogger(ctx, l.logger) @@ -123,7 +139,12 @@ func (l loggingInterceptor) intercept(ctx context.Context, req interface{}, info return resp, err } -func (l loggingInterceptor) interceptStream(srv interface{}, ss grpc.ServerStream, info *grpc.StreamServerInfo, handler grpc.StreamHandler) error { +func (l loggingInterceptor) interceptStream( + srv interface{}, + ss grpc.ServerStream, + info *grpc.StreamServerInfo, + handler grpc.StreamHandler, +) error { startTime := time.Now() ctx := WithLogger(ss.Context(), l.logger) @@ -141,7 +162,8 @@ func (l loggingInterceptor) interceptStream(srv interface{}, ss grpc.ServerStrea return err } -// requestFromContext creates gRPC request details with information extracted from the request context +// requestFromContext creates gRPC request details with information extracted from the request +// context func (l *loggingInterceptor) requestFromContext(ctx context.Context, method string) *GRPCRequest { request := &GRPCRequest{Method: method} @@ -169,7 +191,12 @@ func (l *loggingInterceptor) requestFromContext(ctx context.Context, method stri // logStatus adds the gRPC Status to the log context. // If the response is an internal server error, log that as an Error // returns true if the logging was handled (e.g. internal server error) -func (l *loggingInterceptor) log(ctx context.Context, err error, method string, request *GRPCRequest) { +func (l *loggingInterceptor) log( + ctx context.Context, + err error, + method string, + request *GRPCRequest, +) { if !l.filterRPC(ctx, method, err) { return } @@ -196,13 +223,18 @@ func (l *loggingInterceptor) log(ctx context.Context, err error, method string, }, } - // if we reach here, the response either wasn't a bad error worth handling (e.g. NotFound and its ilk) + // if we reach here, the response either wasn't a bad error worth handling (e.g. NotFound and + // its ilk) ctxlogrus.Extract(ctx).WithField("httpRequest", httpReq).Infof("served RPC %v", method) } // handleError adds grpcStatus to logentry, and can handle our most egregious errors // returns true if the default Info logger should be skipped -func (l *loggingInterceptor) handleError(ctx context.Context, err error, method string) (handled bool) { +func (l *loggingInterceptor) handleError( + ctx context.Context, + err error, + method string, +) (handled bool) { if err == nil { return false } @@ -261,7 +293,11 @@ func RecoveryMiddleware(next http.Handler) http.Handler { entry := ctxlogrus.Extract(ctx) // write error back to client - jsonStatus, merr := protojson.MarshalOptions{EmitUnpopulated: true}.Marshal(stErr.Proto()) + jsonStatus, merr := protojson.MarshalOptions{ + EmitUnpopulated: true, + }.Marshal( + stErr.Proto(), + ) if merr != nil { entry.WithError(merr).Errorf("error marshalling error status into log") fmt.Fprint(w, `{"error": "server_error"}`) @@ -280,7 +316,12 @@ func RecoveryMiddleware(next http.Handler) http.Handler { // UnaryRecoveryInterceptor is an interceptor that recovers panics and turns them // into nicer GRPC errors. -func UnaryRecoveryInterceptor(ctx context.Context, req interface{}, _ *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (resp interface{}, err error) { +func UnaryRecoveryInterceptor( + ctx context.Context, + req interface{}, + _ *grpc.UnaryServerInfo, + handler grpc.UnaryHandler, +) (resp interface{}, err error) { defer func() { e := recover() if e == nil { @@ -306,7 +347,12 @@ func UnaryRecoveryInterceptor(ctx context.Context, req interface{}, _ *grpc.Unar // StreamRecoveryInterceptor is an interceptor that recovers panics from // Streaming services and turns them into nicer gRPC errors. -func StreamRecoveryInterceptor(srv interface{}, ss grpc.ServerStream, _ *grpc.StreamServerInfo, handler grpc.StreamHandler) (err error) { +func StreamRecoveryInterceptor( + srv interface{}, + ss grpc.ServerStream, + _ *grpc.StreamServerInfo, + handler grpc.StreamHandler, +) (err error) { defer func() { e := recover() if e == nil { @@ -333,7 +379,10 @@ func StreamRecoveryInterceptor(srv interface{}, ss grpc.ServerStream, _ *grpc.St // server error response back to return to the client func errWithStack(ctx context.Context, err error) *status.Status { stack := debug.Stack() - ctxlogrus.Extract(ctx).WithError(err).WithField("stackTrace", string(stack)).Error("panic handling request") + ctxlogrus.Extract(ctx). + WithError(err). + WithField("stackTrace", string(stack)). + Error("panic handling request") serverError := status.New(codes.Internal, "server error") reqID, _ := uuid.NewV4() diff --git a/middleware_options.go b/middleware_options.go index 3dabae5..3341ba3 100644 --- a/middleware_options.go +++ b/middleware_options.go @@ -73,7 +73,8 @@ func DefaultFilterRPC(_ context.Context, fullMethod string, _ error) bool { } } -// DefaultFilterHTTP filters health checks and monitoring canaries from some well known user agents or URL paths. +// DefaultFilterHTTP filters health checks and monitoring canaries from some well known user agents +// or URL paths. func DefaultFilterHTTP(r *http.Request) bool { userAgent := r.Header.Get("User-Agent") switch { diff --git a/middleware_test.go b/middleware_test.go index eb87bc8..33e04c6 100644 --- a/middleware_test.go +++ b/middleware_test.go @@ -57,7 +57,11 @@ func (s *logFormatterSuite) TestPanic() { reqID = ri.RequestId } } - assert.NotEmpty(s.T(), reqID, "panic in RPC returns a requestID to correlate logs back to client-reported error") + assert.NotEmpty( + s.T(), + reqID, + "panic in RPC returns a requestID to correlate logs back to client-reported error", + ) _ = s.getOutputJSONs() } @@ -107,7 +111,8 @@ func (s *logFormatterSuite) TestError() { if tcase.logError { assert.Equal(s.T(), "ERROR", msgs[0]["severity"], "error is logged as error") - assert.Equal(s.T(), + assert.Equal( + s.T(), "type.googleapis.com/google.devtools.clouderrorreporting.v1beta1.ReportedErrorEvent", msgs[0]["@type"], "errors are typed to force Error Reporting parsing", diff --git a/stackskip_test.go b/stackskip_test.go index ba23a37..0dc5564 100644 --- a/stackskip_test.go +++ b/stackskip_test.go @@ -3,13 +3,27 @@ package logadapter import ( "bytes" "encoding/json" + "runtime" "testing" + "github.com/gofrs/uuid" + "go.opentelemetry.io/otel/trace" + "github.com/Mattel/logrus-stackdriver-formatter/test" "github.com/google/go-cmp/cmp" "github.com/sirupsen/logrus" ) +var ( + TraceFlags = trace.FlagsSampled + TraceID = uuid.Must(uuid.FromString("105445aa7843bc8bf206b12000100000")) + SpanID = [8]byte{0, 0, 0, 0, 0, 0, 0, 1} + SpanContext = trace.SpanContext{}.WithSpanID(SpanID). + WithTraceID(trace.TraceID(TraceID)). + WithTraceFlags(TraceFlags) + LineNumber = platformLine() +) + func TestStackSkip(t *testing.T) { var out bytes.Buffer @@ -21,21 +35,24 @@ func TestStackSkip(t *testing.T) { WithVersion("0.1"), WithStackSkip("github.com/Mattel/logrus-stackdriver-formatter"), WithSkipTimestamp(), + WithGlobalTraceID(TraceID), ) mylog := test.LogWrapper{ Logger: logger, } - mylog.Error("my log entry") + mylog.Logger. + WithField("span_context", SpanContext). + Error("my log entry") want := map[string]interface{}{ - "@type": reportedErrorEventType, - "severity": "ERROR", - "message": "my log entry", - "logName": "projects/test-project/logs/test", - "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", - "logging.googleapis.com/spanId": "1", - "logging.googleapis.com/traceSampled": true, + "@type": reportedErrorEventType, + "severity": "ERROR", + "message": "my log entry", + "logName": "projects/test-project/logs/test", + "logging.googleapis.com/trace": "projects/test-project/traces/105445aa7843bc8bf206b12000100000", + "logging.googleapis.com/spanId": "0000000000000001", + "logging.googleapis.com/trace_sampled": true, "serviceContext": map[string]interface{}{ "service": "test", "version": "0.1", @@ -43,13 +60,13 @@ func TestStackSkip(t *testing.T) { "context": map[string]interface{}{ "reportLocation": map[string]interface{}{ "filePath": "testing/testing.go", - "lineNumber": 1194.0, + "lineNumber": LineNumber, "functionName": "tRunner", }, }, - "sourceLocation": map[string]interface{}{ + "logging.googleapis.com/sourceLocation": map[string]interface{}{ "file": "testing/testing.go", - "line": 1194.0, + "line": LineNumber, "function": "tRunner", }, } @@ -63,3 +80,14 @@ func TestStackSkip(t *testing.T) { t.Errorf("Unexpected output (-want +got):\n%s", diff) } } + +func platformLine() float64 { + switch runtime.GOOS { + case "darwin": + return 1193.0 + case "linux": + return 1439.0 + default: // does anyone really use windows? + return 0.0 + } +} diff --git a/stacktrace.go b/stacktrace.go index 6bfe31e..615ee7a 100644 --- a/stacktrace.go +++ b/stacktrace.go @@ -36,7 +36,10 @@ func extractStackFromError(err error) []byte { fn := runtime.FuncForPC(pc) if fn != nil { file, line := fn.FileLine(pc) - lines = append(lines, fmt.Sprintf("%s()\n\t%s:%d +%#x", fn.Name(), file, line, fn.Entry())) + lines = append( + lines, + fmt.Sprintf("%s()\n\t%s:%d +%#x", fn.Name(), file, line, fn.Entry()), + ) } } buf.WriteString(strings.Join(lines, "\n")) diff --git a/suite_test.go b/suite_test.go index 1f6ef97..d14bb04 100644 --- a/suite_test.go +++ b/suite_test.go @@ -36,7 +36,10 @@ func newGRPCTestSuite(t *testing.T) *grpcTestSuite { logadapter.WithService("logging-test"), logadapter.WithVersion("v1.0.0"), logadapter.WithStackTraceStyle(logadapter.TraceInPayload), - logadapter.WithSourceReference("github.com/Mattel/logrus-stackdriver-formatter", "v1.0.0"), + logadapter.WithSourceReference( + "github.com/Mattel/logrus-stackdriver-formatter", + "v1.0.0", + ), logadapter.WithPrettyPrint(), ) var out io.Writer @@ -68,7 +71,10 @@ type loggingPingService struct { pb_testproto.TestServiceServer } -func (s *loggingPingService) Ping(ctx context.Context, ping *pb_testproto.PingRequest) (*pb_testproto.PingResponse, error) { +func (s *loggingPingService) Ping( + ctx context.Context, + ping *pb_testproto.PingRequest, +) (*pb_testproto.PingResponse, error) { grpc_ctxtags.Extract(ctx).Set("custom_tags.string", "something").Set("custom_tags.int", 1337) ctxlogrus.AddFields(ctx, logrus.Fields{"custom_field": "custom_value"}) ctxlogrus.Extract(ctx).Info("some ping") @@ -78,7 +84,10 @@ func (s *loggingPingService) Ping(ctx context.Context, ping *pb_testproto.PingRe return s.TestServiceServer.Ping(ctx, ping) } -func (s *loggingPingService) PingError(ctx context.Context, ping *pb_testproto.PingRequest) (*pb_testproto.Empty, error) { +func (s *loggingPingService) PingError( + ctx context.Context, + ping *pb_testproto.PingRequest, +) (*pb_testproto.Empty, error) { empty, err := s.TestServiceServer.PingError(ctx, ping) if ping.Value == "stack" { @@ -89,14 +98,22 @@ func (s *loggingPingService) PingError(ctx context.Context, ping *pb_testproto.P return empty, err } -func (s *loggingPingService) PingList(ping *pb_testproto.PingRequest, stream pb_testproto.TestService_PingListServer) error { - grpc_ctxtags.Extract(stream.Context()).Set("custom_tags.string", "something").Set("custom_tags.int", 1337) +func (s *loggingPingService) PingList( + ping *pb_testproto.PingRequest, + stream pb_testproto.TestService_PingListServer, +) error { + grpc_ctxtags.Extract(stream.Context()). + Set("custom_tags.string", "something"). + Set("custom_tags.int", 1337) ctxlogrus.AddFields(stream.Context(), logrus.Fields{"custom_field": "custom_value"}) ctxlogrus.Extract(stream.Context()).Info("some pinglist") return s.TestServiceServer.PingList(ping, stream) } -func (s *loggingPingService) PingEmpty(ctx context.Context, empty *pb_testproto.Empty) (*pb_testproto.PingResponse, error) { +func (s *loggingPingService) PingEmpty( + ctx context.Context, + empty *pb_testproto.Empty, +) (*pb_testproto.PingResponse, error) { return s.TestServiceServer.PingEmpty(ctx, empty) } @@ -141,7 +158,10 @@ func newHTTPTestSuite(t *testing.T) *httpTestSuite { logadapter.WithService("logging-test"), logadapter.WithVersion("v1.0.0"), logadapter.WithStackTraceStyle(logadapter.TraceInPayload), - logadapter.WithSourceReference("github.com/Mattel/logrus-stackdriver-formatter", "v1.0.0"), + logadapter.WithSourceReference( + "github.com/Mattel/logrus-stackdriver-formatter", + "v1.0.0", + ), logadapter.WithPrettyPrint(), ) var out io.Writer