Slog Handler Elastic APM Integration

Implemented a slog handler that attached trace/correlation logs (if available) to the log message. Also will report specific log level logs as errors through an apm tracer.
elastic · Mar 25, 2024 · 89ec28b · 89ec28b
1 parent d6810ab
commit 89ec28b
Show file tree

Hide file tree

Showing 5 changed files with 485 additions and 0 deletions.
diff --git a/module/apmslog/example_test.go b/module/apmslog/example_test.go
@@ -0,0 +1,74 @@
+// Licensed to Elasticsearch B.V. under one or more contributor
+// license agreements. See the NOTICE file distributed with
+// this work for additional information regarding copyright
+// ownership. Elasticsearch B.V. licenses this file to you under
+// the Apache License, Version 2.0 (the "License"); you may
+// not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied.  See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+package apmslog_test
+
+import (
+	"context"
+	"log/slog"
+	"os"
+
+	"go.elastic.co/apm/module/apmslog/v2"
+	"go.elastic.co/apm/v2"
+)
+
+func ExampleHandler() {
+	// Report slog "ERROR" level messages to Elastic APM using
+	// apm.DefaultTracer() while utilizing slog.Default().Handler()
+	// to format logging messages
+	apmHandler := apmslog.NewApmHandler()
+	logger := slog.New(apmHandler)
+
+	// Report slog "ERROR" level messages to Elastic APM using
+	// some specific tracer while utilizing slog.Default().Handler()
+	// to format logging messages
+	apmHandler = apmslog.NewApmHandler(
+		apmslog.WithTracer(&apm.Tracer{}),
+	)
+	logger = slog.New(apmHandler)
+
+	// Report slog "ERROR" and "WARN level messages to Elastic APM using
+	// apm.DefaultTracer() while utilizing slog.Default().Handler()
+	// to format logging messages
+	apmHandler = apmslog.NewApmHandler(
+		apmslog.WithReportLevel([]slog.Level{slog.LevelError, slog.LevelWarn}),
+	)
+	logger = slog.New(apmHandler)
+
+	// Report slog "ERROR" level messages to Elastic APM using
+	// apm.DefaultTracer() while utilizing some specific slog handler
+	// to format logging messages
+	apmHandler = apmslog.NewApmHandler(
+		apmslog.WithHandler(
+			slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{
+				Level: slog.LevelInfo,
+			}),
+		),
+	)
+	logger = slog.New(apmHandler)
+
+	// while using slog context aware methods, any existing trace,
+	// transaction, or span ID are added from the given context
+	tx := apm.DefaultTracer().StartTransaction("name", "type")
+	defer tx.End()
+
+	ctx := apm.ContextWithTransaction(context.Background(), tx)
+	span, ctx := apm.StartSpan(ctx, "name", "type")
+	defer span.End()
+
+	logger.InfoContext(ctx, "I should have a trace, transaction, and span id attached!")
+}
diff --git a/module/apmslog/go.mod b/module/apmslog/go.mod
@@ -0,0 +1,26 @@
+module go.elastic.co/apm/module/apmslog/v2
+
+require (
+	github.com/pkg/errors v0.9.1
+	github.com/stretchr/testify v1.8.4
+	go.elastic.co/apm/v2 v2.5.0
+)
+
+require (
+	github.com/armon/go-radix v1.0.0 // indirect
+	github.com/davecgh/go-spew v1.1.1 // indirect
+	github.com/elastic/go-sysinfo v1.7.1 // indirect
+	github.com/elastic/go-windows v1.0.0 // indirect
+	github.com/google/go-cmp v0.5.4 // indirect
+	github.com/joeshaw/multierror v0.0.0-20140124173710-69b34d4ec901 // indirect
+	github.com/pmezard/go-difflib v1.0.0 // indirect
+	github.com/prometheus/procfs v0.0.0-20190425082905-87a4384529e0 // indirect
+	go.elastic.co/fastjson v1.1.0 // indirect
+	golang.org/x/sys v0.8.0 // indirect
+	gopkg.in/yaml.v3 v3.0.1 // indirect
+	howett.net/plist v0.0.0-20181124034731-591f970eefbb // indirect
+)
+
+replace go.elastic.co/apm/v2 => ../..
+
+go 1.19
diff --git a/module/apmslog/go.sum b/module/apmslog/go.sum
@@ -0,0 +1,63 @@
+github.com/armon/go-radix v1.0.0 h1:F4z6KzEeeQIMeLFa97iZU6vupzoecKdU5TX24SNppXI=
+github.com/armon/go-radix v1.0.0/go.mod h1:ufUuZ+zHj4x4TnLV4JWEpy2hxWSpsRywHrMgIH9cCH8=
+github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
+github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/elastic/go-sysinfo v1.7.1 h1:Wx4DSARcKLllpKT2TnFVdSUJOsybqMYCNQZq1/wO+s0=
+github.com/elastic/go-sysinfo v1.7.1/go.mod h1:i1ZYdU10oLNfRzq4vq62BEwD2fH8KaWh6eh0ikPT9F0=
+github.com/elastic/go-windows v1.0.0 h1:qLURgZFkkrYyTTkvYpsZIgf83AUsdIHfvlJaqaZ7aSY=
+github.com/elastic/go-windows v1.0.0/go.mod h1:TsU0Nrp7/y3+VwE82FoZF8gC/XFg/Elz6CcloAxnPgU=
+github.com/google/go-cmp v0.5.4 h1:L8R9j+yAqZuZjsqh/z+F1NCffTKKLShY6zXTItVIZ8M=
+github.com/google/go-cmp v0.5.4/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
+github.com/jessevdk/go-flags v1.4.0/go.mod h1:4FA24M0QyGHXBuZZK/XkWh8h0e1EYbRYJSGM75WSRxI=
+github.com/joeshaw/multierror v0.0.0-20140124173710-69b34d4ec901 h1:rp+c0RAYOWj8l6qbCUTSiRLG/iKnW3K3/QfPPuSsBt4=
+github.com/joeshaw/multierror v0.0.0-20140124173710-69b34d4ec901/go.mod h1:Z86h9688Y0wesXCyonoVr47MasHilkuLMqGhRZ4Hpak=
+github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI=
+github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo=
+github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
+github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE=
+github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
+github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
+github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
+github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
+github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
+github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
+github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
+github.com/prometheus/procfs v0.0.0-20190425082905-87a4384529e0 h1:c8R11WC8m7KNMkTv/0+Be8vvwo4I3/Ut9AC2FW8fX3U=
+github.com/prometheus/procfs v0.0.0-20190425082905-87a4384529e0/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsTZCD3I8kEA=
+github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
+github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
+github.com/stretchr/testify v1.8.4 h1:CcVxjf3Q8PM0mHUKJCdn+eZZtm5yQwehR5yeSVQQcUk=
+github.com/stretchr/testify v1.8.4/go.mod h1:sz/lmYIOXD/1dqDmKjjqLyZ2RngseejIcXlSw2iwfAo=
+github.com/yuin/goldmark v1.1.27/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74=
+go.elastic.co/fastjson v1.1.0 h1:3MrGBWWVIxe/xvsbpghtkFoPciPhOCmjsR/HfwEeQR4=
+go.elastic.co/fastjson v1.1.0/go.mod h1:boNGISWMjQsUPy/t6yqt2/1Wx4YNPSe+mZjlyw9vKKI=
+golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
+golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
+golang.org/x/mod v0.2.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
+golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
+golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
+golang.org/x/net v0.0.0-20200226121028-0de0cce0169b/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
+golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sync v0.0.0-20190911185100-cd5d95a43a6e/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
+golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20191025021431-6c3a3bfe00ae/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.8.0 h1:EBmGv8NaZBZTWvrbjNoL6HVt+IVy3QDQpJs7VRIw3tU=
+golang.org/x/sys v0.8.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
+golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
+golang.org/x/tools v0.0.0-20200509030707-2212a7e161a5/go.mod h1:EkVYQZoAsY45+roYkvgYkIh4xh/qjgUK9TdY2XT94GE=
+golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+golang.org/x/xerrors v0.0.0-20220907171357-04be3eba64a2 h1:H2TDz8ibqkAF6YGhCdN3jS9O0/s90v0rJh3X/OLHEUk=
+gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
+gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127 h1:qIbj1fsPNlZgppZ+VLlY7N33q108Sa+fhmuc+sWQYwY=
+gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
+gopkg.in/yaml.v2 v2.2.1/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
+gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
+gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
+howett.net/plist v0.0.0-20181124034731-591f970eefbb h1:jhnBjNi9UFpfpl8YZhA9CrOqpnJdvzuiHsl/dnxl11M=
+howett.net/plist v0.0.0-20181124034731-591f970eefbb/go.mod h1:vMygbs4qMhSZSc4lCUl2OEE+rDiIIJAIdR4m7MiMcm0=
diff --git a/module/apmslog/handler.go b/module/apmslog/handler.go
@@ -0,0 +1,175 @@
+// Licensed to Elasticsearch B.V. under one or more contributor
+// license agreements. See the NOTICE file distributed with
+// this work for additional information regarding copyright
+// ownership. Elasticsearch B.V. licenses this file to you under
+// the Apache License, Version 2.0 (the "License"); you may
+// not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied.  See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+package apmslog // import "go.elastic.co/apm/module/apmslog/v2"
+
+import (
+	"context"
+	"errors"
+
+	"log/slog"
+	"slices"
+	"strings"
+
+	"go.elastic.co/apm/v2"
+)
+
+const (
+	// FieldKeyTraceID is the field key for the trace ID.
+	FieldKeyTraceID = "trace.id"
+
+	// FieldKeyTransactionID is the field key for the transaction ID.
+	FieldKeyTransactionID = "transaction.id"
+
+	// FieldKeySpanID is the field key for the span ID.
+	FieldKeySpanID = "span.id"
+)
+
+type ApmHandler struct {
+	Tracer       *apm.Tracer
+	ReportLevels []slog.Level
+	Handler      slog.Handler
+}
+
+func (s *ApmHandler) tracer() *apm.Tracer {
+	if s.Tracer == nil {
+		return apm.DefaultTracer()
+	}
+	return s.Tracer
+}
+
+func (s *ApmHandler) levels() []slog.Level {
+	if s.ReportLevels == nil {
+		return []slog.Level{slog.LevelError}
+	}
+	return s.ReportLevels
+}
+
+// Enabled reports whether the handler handles records at the given level.
+func (s *ApmHandler) Enabled(ctx context.Context, level slog.Level) bool {
+	return s.Handler.Enabled(ctx, level)
+}
+
+// WithAttrs returns a new ApmHandler with passed attributes attached.
+func (s *ApmHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	return &ApmHandler{s.Tracer, s.ReportLevels, s.Handler.WithAttrs(attrs)}
+}
+
+// WithGroup returns a new ApmHandler with passed group attached.
+func (s *ApmHandler) WithGroup(name string) slog.Handler {
+	return &ApmHandler{s.Tracer, s.ReportLevels, s.Handler.WithGroup(name)}
+}
+
+func (s *ApmHandler) Handle(ctx context.Context, r slog.Record) error {
+
+	// report record as APM error
+	tracer := s.tracer()
+	if slices.Contains(s.levels(), r.Level) && tracer.Recording() {
+
+		// attempt to find error/err attribute
+		// slog doesnt have a standardard way of attaching an
+		// error to a record, so attempting to grab any attribute
+		// that has error/err as key and extracting the value
+		// seems like a likely way to do it.
+		var err error
+		r.Attrs(func(a slog.Attr) bool {
+			if a.Key == "error" || a.Key == "err" {
+				if v, ok := a.Value.Any().(error); ok {
+					err = v
+					return false
+				}
+				if v, ok := a.Value.Any().(string); ok {
+					err = errors.New(v)
+					return false
+				}
+				return false
+			}
+			return true
+		})
+		// if error/err attribute exists, use it as Error value
+		var errLogRecord apm.ErrorLogRecord
+		if err != nil {
+			errLogRecord = apm.ErrorLogRecord{
+				Message: r.Message,
+				Level:   strings.ToLower(r.Level.String()),
+				Error:   err,
+			}
+		} else {
+			errLogRecord = apm.ErrorLogRecord{
+				Message: r.Message,
+				Level:   strings.ToLower(r.Level.String()),
+			}
+		}
+
+		errlog := tracer.NewErrorLog(errLogRecord)
+		errlog.Handled = true
+		// Time is a default slog attribute. If it exists, extract it
+		// else use default r.Time (time which log was called)
+		errlog.Timestamp = r.Time.UTC()
+		errlog.SetStacktrace(2)
+
+		// and include it in the reported error.
+		if tx := apm.TransactionFromContext(ctx); tx != nil {
+			errlog.TraceID = tx.TraceContext().Trace
+			errlog.TransactionID = tx.TraceContext().Span
+			errlog.ParentID = tx.TraceContext().Span
+		}
+		if span := apm.SpanFromContext(ctx); span != nil {
+			errlog.ParentID = span.TraceContext().Span
+		}
+		errlog.Send()
+	}
+
+	// attach trace context if exists and attach to record
+	if tx := apm.TransactionFromContext(ctx); tx != nil {
+		r.Add(FieldKeyTraceID, tx.TraceContext().Trace)
+		r.Add(FieldKeyTransactionID, tx.TraceContext().Span)
+	}
+	if span := apm.SpanFromContext(ctx); span != nil {
+		r.Add(FieldKeySpanID, span.TraceContext().Span)
+	}
+
+	return s.Handler.Handle(ctx, r)
+}
+
+type apmHandlerOption func(h *ApmHandler)
+
+func NewApmHandler(opts ...apmHandlerOption) *ApmHandler {
+	h := &ApmHandler{apm.DefaultTracer(), []slog.Level{slog.LevelError}, slog.Default().Handler()}
+	for _, opt := range opts {
+		opt(h)
+	}
+	return h
+}
+
+func WithHandler(handler slog.Handler) apmHandlerOption {
+	return func(h *ApmHandler) {
+		h.Handler = handler
+	}
+}
+
+func WithReportLevel(lvls []slog.Level) apmHandlerOption {
+	return func(h *ApmHandler) {
+		h.ReportLevels = lvls
+	}
+}
+
+func WithTracer(tracer *apm.Tracer) apmHandlerOption {
+	return func(h *ApmHandler) {
+		h.Tracer = tracer
+	}
+}