Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

add GCP optimized slog package #9

Merged
merged 3 commits into from
Feb 5, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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.
91 changes: 91 additions & 0 deletions gcp/README.md
Original file line number Diff line number Diff line change
@@ -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.
Binary file added gcp/basic.png
Loading
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.
Binary file added gcp/correlated.png
Loading
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.
11 changes: 11 additions & 0 deletions gcp/init/init.go
Original file line number Diff line number Diff line change
@@ -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))) }
60 changes: 60 additions & 0 deletions gcp/setup.go
Original file line number Diff line number Diff line change
@@ -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)}
}
67 changes: 67 additions & 0 deletions gcp/trace.go
Original file line number Diff line number Diff line change
@@ -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)
}
Loading