Skip to content

Commit

Permalink
New Relic Slog Instrumentation
Browse files Browse the repository at this point in the history
Automatically configure slog to integrate with New
Relic logs in context using this tooling.
  • Loading branch information
iamemilio committed Feb 7, 2024
1 parent 555b143 commit 889e167
Show file tree
Hide file tree
Showing 4 changed files with 437 additions and 0 deletions.
19 changes: 19 additions & 0 deletions v3/integrations/logcontext-v2/nrslog/go.mod
Original file line number Diff line number Diff line change
@@ -0,0 +1,19 @@
module github.com/newrelic/go-agent/v3/integrations/logcontext-v2/nrslog

go 1.21.6

require (
github.com/newrelic/go-agent/v3 v3.29.1
github.com/newrelic/go-agent/v3/integrations/logcontext-v2/logWriter v1.0.1
)

require (
github.com/golang/protobuf v1.5.3 // indirect
github.com/newrelic/go-agent/v3/integrations/logcontext-v2/nrwriter v1.0.0 // indirect
golang.org/x/net v0.9.0 // indirect
golang.org/x/sys v0.7.0 // indirect
golang.org/x/text v0.9.0 // indirect
google.golang.org/genproto v0.0.0-20230410155749-daa745c078e1 // indirect
google.golang.org/grpc v1.56.3 // indirect
google.golang.org/protobuf v1.30.0 // indirect
)
178 changes: 178 additions & 0 deletions v3/integrations/logcontext-v2/nrslog/handler.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,178 @@
package nrslog

import (
"context"
"io"
"log/slog"

"github.com/newrelic/go-agent/v3/newrelic"
)

type NRHandler struct {
handler slog.Handler
w *LogWriter
app *newrelic.Application
txn *newrelic.Transaction
}

// TextHandler creates a wrapped slog TextHandler, enabling it to both automatically capture logs
// and to enrich logs locally depending on your logs in context configuration in your New Relic
// application.
func TextHandler(app *newrelic.Application, w io.Writer, opts *slog.HandlerOptions) NRHandler {
nrWriter := NewWriter(w, app)
textHandler := slog.NewTextHandler(nrWriter, opts)
wrappedHandler := WrapHandler(app, textHandler)
wrappedHandler.addWriter(&nrWriter)
return wrappedHandler
}

// JSONHandler creates a wrapped slog JSONHandler, enabling it to both automatically capture logs
// and to enrich logs locally depending on your logs in context configuration in your New Relic
// application.
func JSONHandler(app *newrelic.Application, w io.Writer, opts *slog.HandlerOptions) NRHandler {
nrWriter := NewWriter(w, app)
jsonHandler := slog.NewJSONHandler(nrWriter, opts)
wrappedHandler := WrapHandler(app, jsonHandler)
wrappedHandler.addWriter(&nrWriter)
return wrappedHandler
}

// WithTransaction creates a new slog Logger object to be used for logging within a given transaction.
func WithTransaction(txn *newrelic.Transaction, logger *slog.Logger) *slog.Logger {
if txn == nil {
return logger
}

h := logger.Handler()
switch nrHandler := h.(type) {
case NRHandler:
txnHandler := nrHandler.WithTransaction(txn)
return slog.New(txnHandler)
default:
return logger
}
}

// WithTransaction creates a new slog Logger object to be used for logging within a given transaction it its found
// in a context.
func WithContext(ctx context.Context, logger *slog.Logger) *slog.Logger {
if ctx == nil {
return logger
}

txn := newrelic.FromContext(ctx)
return WithTransaction(txn, logger)
}

// WrapHandler returns a new handler that is wrapped with New Relic tools to capture
// log data based on your application's logs in context settings.
func WrapHandler(app *newrelic.Application, handler slog.Handler) NRHandler {
return NRHandler{
handler: handler,
app: app,
}
}

func (h *NRHandler) addWriter(w *LogWriter) {
h.w = w
}

// WithTransaction returns a new handler that is configured to capture log data
// and attribute it to a specific transaction.
func (h NRHandler) WithTransaction(txn *newrelic.Transaction) NRHandler {
handler := NRHandler{
handler: h.handler,
app: h.app,
txn: txn,
}

writer := h.w.WithTransaction(txn)
handler.addWriter(&writer)
return handler
}

// Enabled reports whether the handler handles records at the given level.
// The handler ignores records whose level is lower.
// It is called early, before any arguments are processed,
// to save effort if the log event should be discarded.
// If called from a Logger method, the first argument is the context
// passed to that method, or context.Background() if nil was passed
// or the method does not take a context.
// The context is passed so Enabled can use its values
// to make a decision.
func (h NRHandler) Enabled(ctx context.Context, lvl slog.Level) bool {
return h.handler.Enabled(ctx, lvl)
}

// Handle handles the Record.
// It will only be called when Enabled returns true.
// The Context argument is as for Enabled.
// It is present solely to provide Handlers access to the context's values.
// Canceling the context should not affect record processing.
// (Among other things, log messages may be necessary to debug a
// cancellation-related problem.)
//
// Handle methods that produce output should observe the following rules:
// - If r.Time is the zero time, ignore the time.
// - If r.PC is zero, ignore it.
// - Attr's values should be resolved.
// - If an Attr's key and value are both the zero value, ignore the Attr.
// This can be tested with attr.Equal(Attr{}).
// - If a group's key is empty, inline the group's Attrs.
// - If a group has no Attrs (even if it has a non-empty key),
// ignore it.
func (h NRHandler) Handle(ctx context.Context, record slog.Record) error {
data := newrelic.LogData{
Severity: record.Level.String(),
Timestamp: record.Time.UnixMilli(),
Message: record.Message,
}
if h.txn != nil {
h.txn.RecordLog(data)
} else {
h.app.RecordLog(data)
}

return h.handler.Handle(ctx, record)
}

// WithAttrs returns a new Handler whose attributes consist of
// both the receiver's attributes and the arguments.
// The Handler owns the slice: it may retain, modify or discard it.
func (h NRHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
handler := h.handler.WithAttrs(attrs)
return NRHandler{
handler: handler,
app: h.app,
txn: h.txn,
}

}

// WithGroup returns a new Handler with the given group appended to
// the receiver's existing groups.
// The keys of all subsequent attributes, whether added by With or in a
// Record, should be qualified by the sequence of group names.
//
// How this qualification happens is up to the Handler, so long as
// this Handler's attribute keys differ from those of another Handler
// with a different sequence of group names.
//
// A Handler should treat WithGroup as starting a Group of Attrs that ends
// at the end of the log event. That is,
//
// logger.WithGroup("s").LogAttrs(level, msg, slog.Int("a", 1), slog.Int("b", 2))
//
// should behave like
//
// logger.LogAttrs(level, msg, slog.Group("s", slog.Int("a", 1), slog.Int("b", 2)))
//
// If the name is empty, WithGroup returns the receiver.
func (h NRHandler) WithGroup(name string) slog.Handler {
handler := h.handler.WithGroup(name)
return NRHandler{
handler: handler,
app: h.app,
txn: h.txn,
}
}
158 changes: 158 additions & 0 deletions v3/integrations/logcontext-v2/nrslog/handler_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,158 @@
package nrslog

import (
"bytes"
"log/slog"
"testing"

"github.com/newrelic/go-agent/v3/internal"
"github.com/newrelic/go-agent/v3/internal/integrationsupport"
"github.com/newrelic/go-agent/v3/internal/logcontext"
"github.com/newrelic/go-agent/v3/internal/sysinfo"
"github.com/newrelic/go-agent/v3/newrelic"
)

var (
host, _ = sysinfo.Hostname()
)

func TestHandler(t *testing.T) {
app := integrationsupport.NewTestApp(integrationsupport.SampleEverythingReplyFn,
newrelic.ConfigAppLogDecoratingEnabled(true),
newrelic.ConfigAppLogForwardingEnabled(true),
)
out := bytes.NewBuffer([]byte{})
handler := TextHandler(app.Application, out, &slog.HandlerOptions{})
log := slog.New(handler)
message := "Hello World!"
log.Info(message)
logcontext.ValidateDecoratedOutput(t, out, &logcontext.DecorationExpect{
EntityGUID: integrationsupport.TestEntityGUID,
Hostname: host,
EntityName: integrationsupport.SampleAppName,
})
app.ExpectLogEvents(t, []internal.WantLog{
{
Severity: slog.LevelInfo.String(),
Message: message,
Timestamp: internal.MatchAnyUnixMilli,
},
})
}

func TestJSONHandler(t *testing.T) {
app := integrationsupport.NewTestApp(integrationsupport.SampleEverythingReplyFn,
newrelic.ConfigAppLogDecoratingEnabled(true),
newrelic.ConfigAppLogForwardingEnabled(true),
)
out := bytes.NewBuffer([]byte{})
handler := JSONHandler(app.Application, out, &slog.HandlerOptions{})
log := slog.New(handler)
message := "Hello World!"
log.Info(message)
logcontext.ValidateDecoratedOutput(t, out, &logcontext.DecorationExpect{
EntityGUID: integrationsupport.TestEntityGUID,
Hostname: host,
EntityName: integrationsupport.SampleAppName,
})
app.ExpectLogEvents(t, []internal.WantLog{
{
Severity: slog.LevelInfo.String(),
Message: message,
Timestamp: internal.MatchAnyUnixMilli,
},
})
}

func TestHandlerTransactions(t *testing.T) {
app := integrationsupport.NewTestApp(integrationsupport.SampleEverythingReplyFn,
newrelic.ConfigAppLogDecoratingEnabled(true),
newrelic.ConfigAppLogForwardingEnabled(true),
)

out := bytes.NewBuffer([]byte{})
message := "Hello World!"

handler := TextHandler(app.Application, out, &slog.HandlerOptions{})
log := slog.New(handler)

txn := app.Application.StartTransaction("my txn")
txninfo := txn.GetLinkingMetadata()

txnLogger := WithTransaction(txn, log)
txnLogger.Info(message)

backgroundMsg := "this is a background message"
log.Debug(backgroundMsg)
txn.End()

/*
logcontext.ValidateDecoratedOutput(t, out, &logcontext.DecorationExpect{
EntityGUID: integrationsupport.TestEntityGUID,
Hostname: host,
EntityName: integrationsupport.SampleAppName,
}) */

app.ExpectLogEvents(t, []internal.WantLog{
{
Severity: slog.LevelInfo.String(),
Message: message,
Timestamp: internal.MatchAnyUnixMilli,
SpanID: txninfo.SpanID,
TraceID: txninfo.TraceID,
},
})
}

func TestHandlerTransactionsAndBackground(t *testing.T) {
app := integrationsupport.NewTestApp(integrationsupport.SampleEverythingReplyFn,
newrelic.ConfigAppLogDecoratingEnabled(true),
newrelic.ConfigAppLogForwardingEnabled(true),
)

out := bytes.NewBuffer([]byte{})
message := "Hello World!"
messageTxn := "Hello Transaction!"
messageBackground := "Hello Background!"

handler := TextHandler(app.Application, out, &slog.HandlerOptions{})
log := slog.New(handler)

log.Info(message)

txn := app.Application.StartTransaction("my txn")
txninfo := txn.GetLinkingMetadata()

txnLogger := WithTransaction(txn, log)
txnLogger.Info(messageTxn)

log.Warn(messageBackground)
txn.End()

/*
logcontext.ValidateDecoratedOutput(t, out, &logcontext.DecorationExpect{
EntityGUID: integrationsupport.TestEntityGUID,
Hostname: host,
EntityName: integrationsupport.SampleAppName,
}) */

app.ExpectLogEvents(t, []internal.WantLog{
{
Severity: slog.LevelInfo.String(),
Message: message,
Timestamp: internal.MatchAnyUnixMilli,
},
{
Severity: slog.LevelWarn.String(),
Message: messageBackground,
Timestamp: internal.MatchAnyUnixMilli,
},
{
Severity: slog.LevelInfo.String(),
Message: messageTxn,
Timestamp: internal.MatchAnyUnixMilli,
SpanID: txninfo.SpanID,
TraceID: txninfo.TraceID,
},
})
}
Loading

0 comments on commit 889e167

Please sign in to comment.