From 660b1b518b194168a3cf1033ec39a28688e91154 Mon Sep 17 00:00:00 2001 From: cmenke Date: Sun, 24 Mar 2024 19:08:29 -0600 Subject: [PATCH] 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. Add documentation links and clean up comments --- docs/instrumenting.asciidoc | 42 ++++++++ docs/supported-tech.asciidoc | 10 ++ module/apmslog/example_test.go | 74 ++++++++++++++ module/apmslog/go.mod | 26 +++++ module/apmslog/go.sum | 63 ++++++++++++ module/apmslog/handler.go | 173 +++++++++++++++++++++++++++++++++ module/apmslog/handler_test.go | 147 ++++++++++++++++++++++++++++ scripts/Dockerfile-testing | 2 + 8 files changed, 537 insertions(+) create mode 100644 module/apmslog/example_test.go create mode 100644 module/apmslog/go.mod create mode 100644 module/apmslog/go.sum create mode 100644 module/apmslog/handler.go create mode 100644 module/apmslog/handler_test.go diff --git a/docs/instrumenting.asciidoc b/docs/instrumenting.asciidoc index 5be33fb9c..2ecdb89e4 100644 --- a/docs/instrumenting.asciidoc +++ b/docs/instrumenting.asciidoc @@ -776,6 +776,48 @@ func handleRequest(w http.ResponseWriter, req *http.Request) { } ---- +[[builtin-modules-apmslog]] +==== module/apmslog +Package apmslog provides a https://pkg.go.dev/log/slog[slog] Handler +implementation for sending error messages to Elastic APM, as well as automatically +attaching trace context fields to log records while using the context aware +logging methods. + +[source,go] +---- +import ( + "context" + "log/slog" + + "go.elastic.co/apm/module/apmslog/v2" +) + +func ExampleHandler() { + // 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!") +} +---- + [[builtin-modules-apmzerolog]] ==== module/apmzerolog Package apmzerolog provides an implementation of https://github.com/rs/zerolog[Zerolog]'s diff --git a/docs/supported-tech.asciidoc b/docs/supported-tech.asciidoc index 80487d24b..d497a0b4f 100644 --- a/docs/supported-tech.asciidoc +++ b/docs/supported-tech.asciidoc @@ -302,6 +302,16 @@ https://github.com/rs/zerolog/releases/tag/v1.12.0[v1.12.0] and greater. See <> for more information about Zerolog integration. +[float] +==== Slog + +We support log correlation and exception tracking with +https://pkg.go.dev/log/slog/[Slog], +https://pkg.go.dev/log/slog@go1.21.0/[v1.21.0] and greater. + +See <> for more information +about slog integration. + [float] [[supported-tech-object-storage]] === Object Storage diff --git a/module/apmslog/example_test.go b/module/apmslog/example_test.go new file mode 100644 index 000000000..f1f19fb68 --- /dev/null +++ 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 new file mode 100644 index 000000000..eac5ce80b --- /dev/null +++ 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 new file mode 100644 index 000000000..6d5fa577c --- /dev/null +++ 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 new file mode 100644 index 000000000..62d3b9487 --- /dev/null +++ b/module/apmslog/handler.go @@ -0,0 +1,173 @@ +// 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 standard 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 + errlog.Timestamp = r.Time.UTC() + errlog.SetStacktrace(2) + + // extract available trace info from context + 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 + } +} diff --git a/module/apmslog/handler_test.go b/module/apmslog/handler_test.go new file mode 100644 index 000000000..10dd2beb4 --- /dev/null +++ b/module/apmslog/handler_test.go @@ -0,0 +1,147 @@ +// 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 ( + "bytes" + "context" + "io" + "log/slog" + "testing" + "time" + + "github.com/pkg/errors" + "github.com/stretchr/testify/assert" + + "go.elastic.co/apm/module/apmslog/v2" + "go.elastic.co/apm/v2" + "go.elastic.co/apm/v2/transport/transporttest" +) + +func TestHandler(t *testing.T) { + tracer, transport := transporttest.NewRecorderTracer() + defer tracer.Close() + var buf bytes.Buffer + + h := newApmslogHandler(&buf, tracer) + logger := slog.New(h) + + logger.Error("hello world", "error", errors.New("new error")) + + assert.Equal(t, `{"time":"1970-01-01T00:00:00Z","level":"ERROR","msg":"hello world","error":"new error"}`+"\n", buf.String()) + + tracer.Flush(nil) + payloads := transport.Payloads() + assert.Len(t, payloads.Errors, 1) + + err0 := payloads.Errors[0] + assert.Equal(t, "hello world", err0.Log.Message) + assert.Equal(t, "error", err0.Log.Level) + assert.Equal(t, "", err0.Log.LoggerName) + assert.Equal(t, "", err0.Log.ParamMessage) + assert.Equal(t, "TestHandler", err0.Culprit) + assert.NotEmpty(t, err0.Log.Stacktrace) + // assert.Equal(t, model.Time(time.Unix(0, 0).UTC()), err0.Timestamp) // seems like slog time attribute is not accessable + assert.Zero(t, err0.ParentID) + assert.Zero(t, err0.TraceID) + assert.Zero(t, err0.TransactionID) +} +func TestHandlerTransactionTraceContext(t *testing.T) { + tracer, transport := transporttest.NewRecorderTracer() + defer tracer.Close() + + var buf bytes.Buffer + + h := newApmslogHandler(&buf, tracer) + logger := slog.New(h) + + tx := tracer.StartTransaction("name", "type") + ctx := apm.ContextWithTransaction(context.Background(), tx) + span, ctx := apm.StartSpan(ctx, "name", "type") + + logger.ErrorContext(ctx, "hello world", "error", errors.New("new error")) + + span.End() + tx.End() + + tracer.Flush(nil) + payloads := transport.Payloads() + assert.Len(t, payloads.Transactions, 1) + assert.Len(t, payloads.Spans, 1) + assert.Len(t, payloads.Errors, 1) + + err0 := payloads.Errors[0] + assert.Equal(t, payloads.Spans[0].ID, err0.ParentID) + assert.Equal(t, payloads.Transactions[0].TraceID, err0.TraceID) + assert.Equal(t, payloads.Transactions[0].ID, err0.TransactionID) +} + +func TestHandlerWithError(t *testing.T) { + tracer, transport := transporttest.NewRecorderTracer() + defer tracer.Close() + + var buf bytes.Buffer + + h := newApmslogHandler(&buf, tracer) + logger := slog.New(h) + + logger.Error("hello world", "error", mockFuncError()) + + tracer.Flush(nil) + payloads := transport.Payloads() + assert.Len(t, payloads.Errors, 1) + + err0 := payloads.Errors[0] + assert.Equal(t, "new error", err0.Exception.Message) + assert.Equal(t, "hello world", err0.Log.Message) + assert.Equal(t, "mockFuncError", err0.Culprit) + assert.NotEmpty(t, err0.Log.Stacktrace) + assert.NotEmpty(t, err0.Exception.Stacktrace) + assert.NotEqual(t, err0.Log.Stacktrace, err0.Exception.Stacktrace) + assert.Equal(t, "mockFuncError", err0.Exception.Stacktrace[0].Function) + assert.Equal(t, "(*Logger).log", err0.Log.Stacktrace[0].Function) +} + +func mockFuncError() error { + return errors.New("new error") +} + +func TestHandlerTracerClosed(t *testing.T) { + tracer, _ := transporttest.NewRecorderTracer() + tracer.Close() // close it straight away, hook should return immediately + + h := newApmslogHandler(io.Discard, tracer) + logger := slog.New(h) + logger.Error("fail") +} + +func newApmslogHandler(writer io.Writer, tracer *apm.Tracer) *apmslog.ApmHandler { + apmHandler := apmslog.NewApmHandler( + apmslog.WithTracer(tracer), + apmslog.WithHandler(slog.NewJSONHandler(writer, &slog.HandlerOptions{ + Level: slog.LevelInfo, + ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr { + if a.Key == slog.TimeKey { + a.Value = slog.TimeValue(time.Unix(0, 0).UTC()) + } + return a + }, + })), + ) + return apmHandler +} diff --git a/scripts/Dockerfile-testing b/scripts/Dockerfile-testing index 4c18236b7..ae83dd9c3 100644 --- a/scripts/Dockerfile-testing +++ b/scripts/Dockerfile-testing @@ -43,6 +43,7 @@ COPY module/apmprometheus/go.mod module/apmprometheus/go.sum /go/src/go.elastic. COPY module/apmredigo/go.mod module/apmredigo/go.sum /go/src/go.elastic.co/apm/module/apmredigo/ COPY module/apmrestful/go.mod module/apmrestful/go.sum /go/src/go.elastic.co/apm/module/apmrestful/ COPY module/apmrestfulv3/go.mod module/apmrestfulv3/go.sum /go/src/go.elastic.co/apm/module/apmrestfulv3/ +COPY module/apmslog/go.mod module/apmslog/go.sum /go/src/go.elastic.co/apm/module/apmslog/ COPY module/apmsql/go.mod module/apmsql/go.sum /go/src/go.elastic.co/apm/module/apmsql/ COPY module/apmzap/go.mod module/apmzap/go.sum /go/src/go.elastic.co/apm/module/apmzap/ COPY module/apmzerolog/go.mod module/apmzerolog/go.sum /go/src/go.elastic.co/apm/module/apmzerolog/ @@ -89,6 +90,7 @@ RUN cd /go/src/go.elastic.co/apm/module/apmprometheus && go mod download RUN cd /go/src/go.elastic.co/apm/module/apmredigo && go mod download RUN cd /go/src/go.elastic.co/apm/module/apmrestful && go mod download RUN cd /go/src/go.elastic.co/apm/module/apmrestfulv3 && go mod download +RUN cd /go/src/go.elastic.co/apm/module/apmslog && go mod download RUN cd /go/src/go.elastic.co/apm/module/apmsql && go mod download RUN cd /go/src/go.elastic.co/apm/module/apmzap && go mod download RUN cd /go/src/go.elastic.co/apm/module/apmzerolog && go mod download