diff --git a/README.md b/README.md index cd18de4..98294ba 100644 --- a/README.md +++ b/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. diff --git a/gcp/README.md b/gcp/README.md new file mode 100644 index 0000000..5825931 --- /dev/null +++ b/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: + +
+ +## 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: + +
+ +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. diff --git a/gcp/basic.png b/gcp/basic.png new file mode 100644 index 0000000..ec4170c Binary files /dev/null and b/gcp/basic.png differ diff --git a/gcp/correlated.png b/gcp/correlated.png new file mode 100644 index 0000000..0bf8d87 Binary files /dev/null and b/gcp/correlated.png differ diff --git a/gcp/init/init.go b/gcp/init/init.go new file mode 100644 index 0000000..540bc97 --- /dev/null +++ b/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))) } diff --git a/gcp/setup.go b/gcp/setup.go new file mode 100644 index 0000000..2ec97fa --- /dev/null +++ b/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)} +} diff --git a/gcp/trace.go b/gcp/trace.go new file mode 100644 index 0000000..7f4fd46 --- /dev/null +++ b/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) +}