add handler for GCP Cloud Logging

CHANGELOG.md

@@ -10,3 +10,4 @@ to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
 ### Added
 
 - Add sampling handler for sampling records at request level (#3).
+- Add handler to emit JSON logs to GCP Cloud Logging (#6).

README.md

@@ -9,3 +9,4 @@
 Sloth provides opinionated slog handlers for major Cloud providers. It providers following slog handlers:
 
 - [`sampling`](sampling) provides a slog handler for sampling records at request level.
+- [`gcp`](gcp) provides a slog handler for emitting JSON logs to GCP Cloud Logging.

gcp/handler.go

@@ -0,0 +1,253 @@
+// Copyright (c) 2024 The sloth authors
+// Use of this source code is governed by a MIT license found in the LICENSE file.
+
+package gcp
+
+import (
+	"bytes"
+	"context"
+	"encoding/hex"
+	"log/slog"
+	"os"
+	"runtime"
+	"runtime/debug"
+	"slices"
+	"strconv"
+	"strings"
+)
+
+func New(opts ...Option) slog.Handler {
+	option := &options{}
+	for _, opt := range opts {
+		opt(option)
+	}
+	if option.writer == nil {
+		option.writer = os.Stderr
+	}
+
+	var handler slog.Handler
+	handler = slog.NewJSONHandler(
+		option.writer,
+		&slog.HandlerOptions{
+			AddSource:   true,
+			Level:       option.level,
+			ReplaceAttr: replaceAttr(),
+		},
+	)
+	if option.project != "" || option.service != "" {
+		handler = logHandler{
+			handler: handler,
+			project: option.project, contextProvider: option.contextProvider,
+			service: option.service, version: option.version,
+		}
+	}
+
+	return handler
+}
+
+func replaceAttr() func([]string, slog.Attr) slog.Attr {
+	// Replace attributes to match GCP Cloud Logging format.
+	//
+	// [attributes]: https://cloud.google.com/logging/docs/agent/logging/configuration#special-fields
+	replacer := map[string]func(slog.Attr) slog.Attr{
+		// Maps the slog levels to the correct [severity] for GCP Cloud Logging.
+		//
+		// [severity]: https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#LogSeverity
+		slog.LevelKey: func(attr slog.Attr) slog.Attr {
+			var severity string
+			if level, ok := attr.Value.Any().(slog.Level); ok {
+				switch {
+				case level >= slog.LevelError:
+					severity = "ERROR"
+				case level >= slog.LevelWarn:
+					severity = "WARNING"
+				case level >= slog.LevelInfo:
+					severity = "INFO"
+				default:
+					severity = "DEBUG"
+				}
+			}
+
+			return slog.String("severity", severity)
+		},
+		slog.SourceKey: func(attr slog.Attr) slog.Attr {
+			attr.Key = "logging.googleapis.com/sourceLocation"
+
+			return attr
+		},
+		slog.MessageKey: func(attr slog.Attr) slog.Attr {
+			attr.Key = "message"
+
+			return attr
+		},
+		// Format event [timestamp] according to GCP JSON formats.
+		//
+		// [timestamp]: https://cloud.google.com/logging/docs/agent/logging/configuration#timestamp-processing
+		slog.TimeKey: func(attr slog.Attr) slog.Attr {
+			time := attr.Value.Time()
+
+			return slog.Group("timestamp",
+				slog.Int64("seconds", time.Unix()),
+				slog.Int64("nanos", int64(time.Nanosecond())),
+			)
+		},
+	}
+
+	return func(groups []string, attr slog.Attr) slog.Attr {
+		if len(groups) > 0 {
+			return attr
+		}
+
+		if replace, ok := replacer[attr.Key]; ok {
+			return replace(attr)
+		}
+
+		return attr
+	}
+}
+
+type (
+	logHandler struct {
+		handler slog.Handler
+		groups  []group
+
+		project         string
+		contextProvider func(context.Context) TraceContext
+
+		service string
+		version string
+	}
+	group struct {
+		name  string
+		attrs []slog.Attr
+	}
+)
+
+func (h logHandler) Enabled(ctx context.Context, level slog.Level) bool {
+	return h.handler.Enabled(ctx, level)
+}
+
+func (h logHandler) Handle(ctx context.Context, record slog.Record) error { //nolint:funlen
+	handler := h.handler
+
+	if len(h.groups) > 0 {
+		var attr slog.Attr
+		for i := len(h.groups) - 1; i >= 0; i-- {
+			grp := h.groups[i]
+			if grp.attrs == nil {
+				continue
+			}
+
+			attrs := make([]any, 0, len(grp.attrs)+1)
+			attrs = append(attrs, attr)
+			for _, attr := range grp.attrs {
+				attrs = append(attrs, attr)
+			}
+			attr = slog.Group(grp.name, attrs...)
+		}
+		handler = handler.WithAttrs([]slog.Attr{attr})
+	}
+
+	// [Associate logs] with a trace and span.
+	//
+	// [Associate logs]: https://cloud.google.com/trace/docs/trace-log-integration
+	if h.project != "" {
+		const sampled = 0x1
+
+		if traceContext := h.contextProvider(ctx); traceContext.TraceID() != [16]byte{} {
+			traceID := traceContext.TraceID()
+			spanID := traceContext.SpanID()
+			traceFlags := traceContext.TraceFlags()
+			handler = handler.WithAttrs([]slog.Attr{
+				slog.String("logging.googleapis.com/trace", "projects/"+h.project+"/traces/"+hex.EncodeToString(traceID[:])),
+				slog.String("logging.googleapis.com/spanId", hex.EncodeToString(spanID[:])),
+				slog.Bool("logging.googleapis.com/trace_sampled", traceFlags&sampled == sampled),
+			})
+		}
+	}
+
+	// Format log to report [error events].
+	//
+	// [error events]: https://cloud.google.com/error-reporting/docs/formatting-error-messages
+	if record.Level >= slog.LevelError && h.service != "" {
+		firstFrame, _ := runtime.CallersFrames([]uintptr{record.PC}).Next()
+		handler = handler.WithAttrs(
+			[]slog.Attr{
+				slog.Group("context",
+					slog.Group("reportLocation",
+						slog.String("filePath", firstFrame.File),
+						slog.Int("lineNumber", firstFrame.Line),
+						slog.String("functionName", firstFrame.Function),
+					),
+				),
+				slog.Group("serviceContext",
+					slog.String("service", h.service),
+					slog.String("version", h.version),
+				),
+				slog.String("stack_trace", stack(record.Message, firstFrame)),
+			})
+	}
+
+	for _, group := range h.groups {
+		handler = handler.WithGroup(group.name)
+	}
+
+	return handler.Handle(ctx, record)
+}
+
+func stack(message string, firstFrame runtime.Frame) string {
+	stackTrace := &strings.Builder{}
+	stackTrace.WriteString(message)
+	stackTrace.WriteString("\n\n")
+
+	frames := bytes.NewBuffer(debug.Stack())
+	// Always add the first line (goroutine line) in stack trace.
+	firstLine, err := frames.ReadBytes('\n')
+	stackTrace.Write(firstLine)
+	if err != nil {
+		return stackTrace.String()
+	}
+
+	// Each frame has 2 lines in stack trace, first line is the function and second line is the file:#line.
+	firstFuncLine := []byte(firstFrame.Function)
+	firstFileLine := []byte(firstFrame.File + ":" + strconv.Itoa(firstFrame.Line))
+	var functionLine, fileLine []byte
+	for {
+		if functionLine, err = frames.ReadBytes('\n'); err != nil {
+			break
+		}
+		if fileLine, err = frames.ReadBytes('\n'); err != nil {
+			break
+		}
+		if bytes.Contains(functionLine, firstFuncLine) && bytes.Contains(fileLine, firstFileLine) {
+			stackTrace.Write(functionLine)
+			stackTrace.Write(fileLine)
+			_, _ = frames.WriteTo(stackTrace)
+
+			break
+		}
+	}
+
+	return stackTrace.String()
+}
+
+func (h logHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	if len(h.groups) == 0 {
+		h.handler = h.handler.WithAttrs(attrs)
+
+		return h
+	}
+
+	h.groups = slices.Clone(h.groups)
+	h.groups[len(h.groups)-1].attrs = slices.Clone(h.groups[len(h.groups)-1].attrs)
+	h.groups[len(h.groups)-1].attrs = append(h.groups[len(h.groups)-1].attrs, attrs...)
+
+	return h
+}
+
+func (h logHandler) WithGroup(name string) slog.Handler {
+	h.groups = slices.Clone(h.groups)
+	h.groups = append(h.groups, group{name: name})
+
+	return h
+}

gcp/handler_test.go

@@ -0,0 +1,124 @@
+// Copyright (c) 2024 The sloth authors
+// Use of this source code is governed by a MIT license found in the LICENSE file.
+
+package gcp_test
+
+import (
+	"bytes"
+	"context"
+	"encoding/hex"
+	"log/slog"
+	"os"
+	"runtime"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/nil-go/sloth/gcp"
+	"github.com/nil-go/sloth/internal/assert"
+)
+
+//nolint:lll
+func TestHandler(t *testing.T) {
+	t.Parallel()
+
+	testcases := []struct {
+		description string
+		opts        []gcp.Option
+		expected    string
+	}{
+		{
+			description: "default",
+			expected: `{"timestamp":{"seconds":100,"nanos":1000},"severity":"INFO","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":79},"message":"info","a":"A"}
+{"timestamp":{"seconds":100,"nanos":1000},"severity":"WARNING","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":83},"message":"warn","g":{"a":"A"}}
+{"timestamp":{"seconds":100,"nanos":1000},"severity":"ERROR","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":89},"message":"error","g":{"b":"B"}}
+`,
+		},
+		{
+			description: "with level",
+			opts: []gcp.Option{
+				gcp.WithLevel(slog.LevelWarn),
+			},
+			expected: `{"timestamp":{"seconds":100,"nanos":1000},"severity":"WARNING","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":83},"message":"warn","g":{"a":"A"}}
+{"timestamp":{"seconds":100,"nanos":1000},"severity":"ERROR","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":89},"message":"error","g":{"b":"B"}}
+`,
+		},
+		{
+			description: "with error reporting",
+			opts: []gcp.Option{
+				gcp.WithErrorReporting("test", "dev"),
+			},
+			expected: `{"timestamp":{"seconds":100,"nanos":1000},"severity":"INFO","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":79},"message":"info","a":"A"}
+{"timestamp":{"seconds":100,"nanos":1000},"severity":"WARNING","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":83},"message":"warn","g":{"a":"A"}}
+{"timestamp":{"seconds":100,"nanos":1000},"severity":"ERROR","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":89},"message":"error","g":{"b":"B"},"context":{"reportLocation":{"filePath":"/handler_test.go","lineNumber":89,"functionName":"github.com/nil-go/sloth/gcp_test.TestHandler.func2"}},"serviceContext":{"service":"test","version":"dev"},"stack_trace":"error\n\n`,
+		},
+		{
+			description: "with trace",
+			opts: []gcp.Option{
+				gcp.WithTrace("test", func(context.Context) gcp.TraceContext { return traceContext{} }),
+			},
+			expected: `{"timestamp":{"seconds":100,"nanos":1000},"severity":"INFO","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":79},"message":"info","a":"A","logging.googleapis.com/trace":"projects/test/traces/4bf92f3577b34da6a3ce929d0e0e4736","logging.googleapis.com/spanId":"00f067aa0ba902b7","logging.googleapis.com/trace_sampled":true}
+{"timestamp":{"seconds":100,"nanos":1000},"severity":"WARNING","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":83},"message":"warn","logging.googleapis.com/trace":"projects/test/traces/4bf92f3577b34da6a3ce929d0e0e4736","logging.googleapis.com/spanId":"00f067aa0ba902b7","logging.googleapis.com/trace_sampled":true,"g":{"a":"A"}}
+{"timestamp":{"seconds":100,"nanos":1000},"severity":"ERROR","logging.googleapis.com/sourceLocation":{"function":"github.com/nil-go/sloth/gcp_test.TestHandler.func2","file":"/handler_test.go","line":89},"message":"error","g":{"b":"B"},"logging.googleapis.com/trace":"projects/test/traces/4bf92f3577b34da6a3ce929d0e0e4736","logging.googleapis.com/spanId":"00f067aa0ba902b7","logging.googleapis.com/trace_sampled":true}
+`,
+		},
+	}
+
+	for _, testcase := range testcases {
+		testcase := testcase
+
+		t.Run(testcase.description, func(t *testing.T) {
+			t.Parallel()
+
+			buf := &bytes.Buffer{}
+			handler := gcp.New(append(testcase.opts, gcp.WithWriter(buf))...)
+
+			ctx := context.Background()
+			if handler.Enabled(ctx, slog.LevelInfo) {
+				assert.NoError(t, handler.WithAttrs([]slog.Attr{slog.String("a", "A")}).
+					Handle(ctx, record(slog.LevelInfo, "info")))
+			}
+			gHandler := handler.WithGroup("g")
+			if handler.Enabled(ctx, slog.LevelWarn) {
+				record := record(slog.LevelWarn, "warn")
+				record.Add("a", "A")
+				assert.NoError(t, gHandler.Handle(ctx, record))
+			}
+			if handler.Enabled(ctx, slog.LevelError) {
+				assert.NoError(t, gHandler.WithAttrs([]slog.Attr{slog.String("b", "B")}).
+					Handle(ctx, record(slog.LevelError, "error")))
+			}
+
+			path, err := os.Getwd()
+			assert.NoError(t, err)
+			log, _, _ := strings.Cut(buf.String(), "goroutine ")
+			log = strings.ReplaceAll(log, path, "")
+			assert.Equal(t, testcase.expected, log)
+		})
+	}
+}
+
+func record(level slog.Level, message string) slog.Record {
+	var pcs [1]uintptr
+	runtime.Callers(2, pcs[:])
+
+	return slog.NewRecord(time.Unix(100, 1000), level, message, pcs[0])
+}
+
+type traceContext struct{}
+
+func (traceContext) TraceID() [16]byte {
+	b, _ := hex.DecodeString("4bf92f3577b34da6a3ce929d0e0e4736")
+
+	return [16]byte(b)
+}
+
+func (traceContext) SpanID() [8]byte {
+	b, _ := hex.DecodeString("00f067aa0ba902b7")
+
+	return [8]byte(b)
+}
+
+func (traceContext) TraceFlags() byte {
+	return 1
+}