add GCP optimized slog package (#9)

Opening this to gather feedback.

This moves https://github.com/imjasonh/gcpslog into this repo, including
imjasonh/gcpslog#2

---------

Signed-off-by: Jason Hall <[email protected]>

README.md

@@ -4,6 +4,8 @@
 
 Context-aware [`slog`](https://pkg.go.dev/log/slog)
 
+`slog` was added in Go 1.21, so using this requires Go 1.21 or later.
+
 ## Usage
 
 ### Context Logger
@@ -122,3 +124,9 @@ $ go run .
 time=2009-11-10T23:00:00.000Z level=INFO msg="hello world" baz=true foo=bar
 time=2009-11-10T23:00:00.000Z level=ERROR msg="hello world" foo=bar
 ```
+
+### Google Cloud Platform support
+
+This package also provides a GCP-optimized JSON handler for structured logging and trace attribution.
+
+See [`./gcp/README.md`](./gcp/README.md) for details.

gcp/README.md

@@ -0,0 +1,91 @@
+# `clog/gcp`: structured logging for Google Cloud using [`slog`](https://pkg.go.dev/log/slog)
+
+Contrary to the
+[documented "standard" approach for logging](https://cloud.google.com/logging/docs/setup/go),
+this doesn't use any third-party logging package for logging.
+
+Instead, it relies on Google Cloud's support for ingesting structured logs by
+simply printing JSON to stderr.
+
+This method of emitting structured logs is supported by:
+
+- [Cloud Run](https://cloud.google.com/run/docs/logging#using-json)
+- [Kubernetes Engine](https://cloud.google.com/logging/docs/structured-logging#special-payload-fields)
+- [Cloud Functions](https://cloud.google.com/functions/docs/monitoring/logging#writing_structured_logs)
+- [App Engine](https://cloud.google.com/logging/docs/structured-logging#special-payload-fields)
+  (standard and flexible)
+- and in other products, using the
+  [Cloud Logging agent](https://cloud.google.com/logging/docs/agent/logging) and
+  [Ops agent](https://cloud.google.com/logging/docs/agent/ops-agent).
+
+## Basic Usage
+
+To use this, underscore-import `gcp/init`, which will configure `slog` to use
+the GCP-optimized JSON handler for all log messages:
+
+Then when you use `slog`, all log messages will be output in JSON format to
+standard error, which is automatically ingested by Cloud Logging.
+
+```go
+import _ "github.com/chainguard-dev/clog/gcp/init"
+
+...
+
+http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
+  slog.InfoContext(r.Context(), "my message",
+    "mycount", 42,
+    "mystring", "myvalue",
+  )
+})
+```
+
+This logs the message, with the additional structured logging fields in Cloud
+Logging:
+
+<table><tr><td><img src="basic.png" width=50%/></td></tr></table>
+
+## Correlating Logs with Requests
+
+You can also use this to correlate log lines with the request that generated
+them, by associating the log message with the request's trace context header.
+
+```go
+import "github.com/chainguard-dev/clog/gcp"
+
+...
+
+http.Handle("/", gcp.WithCloudTraceContext(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+  slog.InfoContext(r.Context(), "my message",
+    "mycount", 42,
+    "mystring", "myvalue",
+  )
+})))
+```
+
+This logs the message, associated with the request's trace, in Cloud Logging:
+
+<table><tr><td><img src="correlated.png" width=50%/></td></tr></table>
+
+Other logs with the same `trace` attribute are generated by the same incoming
+request.
+
+See https://cloud.google.com/trace/docs/trace-log-integration for more
+information.
+
+## Critical Logging
+
+Cloud Logging supports a **CRITICAL** logging level, which doesn't map cleanly
+to `slog`'s built-in levels.
+
+To log at this level:
+
+```go
+slog.Log(ctx, gcp.LevelCritical, "I have a bad feeling about this...")
+```
+
+See `./cmd/example` for a deployable example.
+
+---
+
+This repo is forked from https://github.com/remko/cloudrun-slog, which
+originated this idea and implementation.

gcp/init/init.go

@@ -0,0 +1,11 @@
+package init
+
+import (
+	"log/slog"
+
+	"github.com/chainguard-dev/clog/gcp"
+)
+
+// Set up structured logging at Info+ level.
+// TODO: Make the level configurable by env var or flag; or just remove the init package.
+func init() { slog.SetDefault(slog.New(gcp.NewHandler(slog.LevelInfo))) }

gcp/setup.go

@@ -0,0 +1,60 @@
+package gcp
+
+import (
+	"context"
+	"log/slog"
+	"os"
+)
+
+// LevelCritical is an extra log level supported by Cloud Logging.
+const LevelCritical = slog.Level(12)
+
+// Handler that outputs JSON understood by the structured log agent.
+// See https://cloud.google.com/logging/docs/agent/logging/configuration#special-fields
+type Handler struct {
+	handler slog.Handler
+}
+
+func NewHandler(level slog.Level) *Handler {
+	return &Handler{handler: slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{
+		AddSource: true,
+		Level:     level,
+		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
+			if a.Key == slog.MessageKey {
+				a.Key = "message"
+			} else if a.Key == slog.SourceKey {
+				a.Key = "logging.googleapis.com/sourceLocation"
+			} else if a.Key == slog.LevelKey {
+				a.Key = "severity"
+				level := a.Value.Any().(slog.Level)
+				if level == LevelCritical {
+					a.Value = slog.StringValue("CRITICAL")
+				}
+			}
+			return a
+		},
+	})}
+}
+
+func (h *Handler) Enabled(ctx context.Context, level slog.Level) bool {
+	return h.handler.Enabled(ctx, level)
+}
+
+func (h *Handler) Handle(ctx context.Context, rec slog.Record) error {
+	if trace := traceFromContext(ctx); trace != "" {
+		rec = rec.Clone()
+		// Add trace ID	to the record so it is correlated with the request log
+		// See https://cloud.google.com/trace/docs/trace-log-integration
+		rec.Add("logging.googleapis.com/trace", slog.StringValue(trace))
+	}
+
+	return h.handler.Handle(ctx, rec)
+}
+
+func (h *Handler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	return &Handler{handler: h.handler.WithAttrs(attrs)}
+}
+
+func (h *Handler) WithGroup(name string) slog.Handler {
+	return &Handler{handler: h.handler.WithGroup(name)}
+}

gcp/trace.go

@@ -0,0 +1,67 @@
+package gcp
+
+import (
+	"context"
+	"fmt"
+	"io"
+	"log/slog"
+	"net/http"
+	"os"
+	"strings"
+)
+
+// WithCloudTraceContext returns an http.handler that adds the GCP Cloud Trace
+// ID to the context. This is used to correlate the structured logs with the
+// request log.
+func WithCloudTraceContext(h http.Handler) http.Handler {
+	// Get the project ID from the environment if specified
+	projectID := os.Getenv("GOOGLE_CLOUD_PROJECT")
+	if projectID == "" {
+		// By default use the metadata IP; otherwise use the environment variable
+		// for consistency with https://pkg.go.dev/cloud.google.com/go/compute/metadata#Client.Get
+		host := "169.254.169.254"
+		if h := os.Getenv("GCE_METADATA_HOST"); h != "" {
+			host = h
+		}
+		req, err := http.NewRequest(http.MethodGet, fmt.Sprintf("http://%s/computeMetadata/v1/project/project-id", host), nil)
+		if err != nil {
+			slog.Debug("WithCloudTraceContext: could not get GCP project ID from metadata server", "err", err)
+			return h
+		}
+		req.Header.Set("Metadata-Flavor", "Google")
+		resp, err := http.DefaultClient.Do(req)
+		if err != nil {
+			slog.Debug("WithCloudTraceContext: could not get GCP project ID from metadata server", "err", err)
+			return h
+		}
+		if resp.StatusCode != http.StatusOK {
+			slog.Debug("WithCloudTraceContext: could not get GCP project ID from metadata server", "code", resp.StatusCode, "status", resp.Status)
+			return h
+		}
+		defer resp.Body.Close()
+		all, err := io.ReadAll(resp.Body)
+		if err != nil {
+			slog.Debug("WithCloudTraceContext: could not get GCP project ID from metadata server", "err", err)
+			return h
+		}
+		projectID = string(all)
+	}
+
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		var trace string
+		traceHeader := r.Header.Get("X-Cloud-Trace-Context")
+		traceParts := strings.Split(traceHeader, "/")
+		if len(traceParts) > 0 && len(traceParts[0]) > 0 {
+			trace = fmt.Sprintf("projects/%s/traces/%s", projectID, traceParts[0])
+		}
+		h.ServeHTTP(w, r.WithContext(context.WithValue(r.Context(), "trace", trace)))
+	})
+}
+
+func traceFromContext(ctx context.Context) string {
+	trace := ctx.Value("trace")
+	if trace == nil {
+		return ""
+	}
+	return trace.(string)
+}