Merge pull request #507 from iamemilio/zerolog_in_context

Zerolog in Context

v3/examples/server/main.go

@@ -246,11 +246,22 @@ func browser(w http.ResponseWriter, r *http.Request) {
 	io.WriteString(w, "browser header page")
 }
 
+func logTxnMessage(w http.ResponseWriter, r *http.Request) {
+	txn := newrelic.FromContext(r.Context())
+	txn.RecordLog(newrelic.LogData{
+		Message:  "Log Message",
+		Severity: "info",
+	})
+
+	io.WriteString(w, "A log message was recorded")
+}
+
 func main() {
 	app, err := newrelic.NewApplication(
 		newrelic.ConfigAppName("Example App"),
 		newrelic.ConfigFromEnvironment(),
 		newrelic.ConfigDebugLogger(os.Stdout),
+		newrelic.ConfigAppLogForwardingEnabled(true),
 	)
 	if err != nil {
 		fmt.Println(err)
@@ -274,6 +285,7 @@ func main() {
 	http.HandleFunc(newrelic.WrapHandleFunc(app, "/browser", browser))
 	http.HandleFunc(newrelic.WrapHandleFunc(app, "/async", async))
 	http.HandleFunc(newrelic.WrapHandleFunc(app, "/message", message))
+	http.HandleFunc(newrelic.WrapHandleFunc(app, "/log", logTxnMessage))
 
 	http.HandleFunc("/background", func(w http.ResponseWriter, req *http.Request) {
 		// Transactions started without an http.Request are classified as
@@ -285,5 +297,17 @@ func main() {
 		time.Sleep(150 * time.Millisecond)
 	})
 
+	http.HandleFunc("/background_log", func(w http.ResponseWriter, req *http.Request) {
+		// Logs that occur outside of a transaction are classified as
+		// background logs.
+
+		app.RecordLog(newrelic.LogData{
+			Message:  "Background Log Message",
+			Severity: "info",
+		})
+
+		io.WriteString(w, "A background log message was recorded")
+	})
+
 	http.ListenAndServe(":8000", nil)
 }

v3/integrations/logcontext-v2/nrzerolog/Readme.md

@@ -0,0 +1,95 @@
+# Zerolog In Context
+
+This plugin for zerolog implements the logs in context tooling for the go agent. This hook
+function can be added to any zerolog logger, and will automatically collect the log data
+from zerolog, and send it to New Relic through the go agent. The following Logging features
+are supported by this plugin in the current release:
+
+| Logging Feature | Supported |
+| ------- | --------- |
+| Forwarding | :heavy_check_mark: |
+| Metrics | :heavy_check_mark: |
+| Enrichment | :x: |
+
+## Installation
+
+The nrzerolog plugin, and the go-agent need to be integrated into your code
+in order to use this tool. Make sure to set `newrelic.ConfigAppLogForwardingEnabled(true)`
+in your config settings for the application. This will enable log forwarding
+in the go agent. If you want to disable metrics, set `newrelic.ConfigAppLogMetricsEnabled(false),`.
+Note that the agent sets the default number of logs per harverst cycle to 10000, but that
+number may be reduced by the server. You can manually set this number by setting
+`newrelic.ConfigAppLogForwardingMaxSamplesStored(123),`.
+
+The following example will shows how to install and set up your code to send logs to new relic from zerolog.
+
+```go
+
+import (
+    "github.com/rs/zerolog"
+    "github.com/newrelic/go-agent/v3/newrelic"
+    "github.com/newrelic/go-agent/v3/integrations/logcontext-v2/nrzerolog"
+)
+
+func main() {
+    // Initialize a zerolog logger
+	baseLogger := zerolog.New(os.Stdout)
+
+	app, err := newrelic.NewApplication(
+		newrelic.ConfigFromEnvironment(),
+		newrelic.ConfigAppName("NRZerolog Example"),
+		newrelic.ConfigInfoLogger(os.Stdout),
+		newrelic.ConfigAppLogForwarding(true),
+	)
+	if err != nil {
+		fmt.Println(err)
+		os.Exit(1)
+	}
+
+	// Send logs to New Relic outside of a transaction
+	nrHook := nrzerolog.NewRelicHook{
+		App: app,
+	}
+
+	// Wrap logger with New Relic Hook
+	nrLogger := baseLogger.Hook(nrHook)
+	nrLogger.Info().Msg("Hello World")
+
+	// Send logs to New Relic inside of a transaction
+	txn := app.StartTransaction("My Transaction")
+	ctx := newrelic.NewContext(context.Background(), txn)
+
+	nrTxnHook := nrzerolog.NewRelicHook{
+		App:     app,
+		Context: ctx,
+	}
+
+	txnLogger := baseLogger.Hook(nrTxnHook)
+	txnLogger.Debug().Msg("This is a transaction log")
+
+	txn.End()
+}
+```
+
+## Usage
+
+Please enable the agent to ingest your logs by calling newrelic.ConfigAppLogForwardingEnabled(true),
+when setting up your application. This is not enabled by default.
+
+This integration for the zerolog logging frameworks uses a built in feature
+of the zerolog framework called hook functions. Zerolog loggers can be modified
+to have hook functions run on them before each time a write is executed. When a
+logger is hooked, meaning a hook function was added to that logger with the Hook() 
+funciton, a copy of that logger is created with those changes. Note that zerolog
+will *never* attempt to verify that any hook functions have not been not duplicated, or 
+that fields are not repeated in any way. As a result, we recommend that you create
+a base logger that is configured in the way you prefer to use zerolog. Then you
+create hooked loggers to send log data to New Relic from that base logger.
+
+The plugin captures the log level, and the message from zerolog. It will also collect
+distributed tracing data from your transaction context. At the moment the hook function is
+called in zerolog, a timestamp will be generated for your log. In most cases, this
+timestamp will be the same as the time posted in the zerolog log message, however it is possible that
+there could be a slight offset depending on the the performance of your system.
+
+

v3/integrations/logcontext-v2/nrzerolog/example/main.go

@@ -0,0 +1,53 @@
+package main
+
+import (
+	"context"
+	"fmt"
+	"os"
+	"time"
+
+	"github.com/newrelic/go-agent/v3/integrations/logcontext-v2/nrzerolog"
+	"github.com/newrelic/go-agent/v3/newrelic"
+	"github.com/rs/zerolog"
+)
+
+func main() {
+	baseLogger := zerolog.New(os.Stdout)
+
+	app, err := newrelic.NewApplication(
+		newrelic.ConfigFromEnvironment(),
+		newrelic.ConfigAppName("NRZerolog Example"),
+		newrelic.ConfigInfoLogger(os.Stdout),
+		newrelic.ConfigAppLogForwardingEnabled(true),
+	)
+	if err != nil {
+		fmt.Println(err)
+		os.Exit(1)
+	}
+
+	app.WaitForConnection(5 * time.Second)
+
+	nrHook := nrzerolog.NewRelicHook{
+		App: app,
+	}
+
+	nrLogger := baseLogger.Hook(nrHook)
+	nrLogger.Info().Msg("Hello World")
+
+	// With transaction context
+	txn := app.StartTransaction("My Transaction")
+	ctx := newrelic.NewContext(context.Background(), txn)
+
+	nrTxnHook := nrzerolog.NewRelicHook{
+		App:     app,
+		Context: ctx,
+	}
+
+	txnLogger := baseLogger.Hook(nrTxnHook)
+	txnLogger.Debug().Msg("This is a transaction log")
+
+	txn.End()
+
+	nrLogger.Info().Msg("Goodbye")
+	app.Shutdown(10 * time.Second)
+}

v3/integrations/logcontext-v2/nrzerolog/go.mod

@@ -0,0 +1,8 @@
+module github.com/newrelic/go-agent/v3/integrations/logcontext-v2/nrzerolog
+
+go 1.15
+
+require (
+	github.com/newrelic/go-agent/v3 v3.16.0
+	github.com/rs/zerolog v1.26.1
+)

v3/integrations/logcontext-v2/nrzerolog/hook.go

@@ -0,0 +1,41 @@
+package nrzerolog
+
+import (
+	"context"
+
+	"github.com/newrelic/go-agent/v3/internal"
+	"github.com/newrelic/go-agent/v3/newrelic"
+	"github.com/rs/zerolog"
+)
+
+func init() { internal.TrackUsage("integration", "logcontext", "zerolog") }
+
+type NewRelicHook struct {
+	App     *newrelic.Application
+	Context context.Context
+}
+
+func (h NewRelicHook) Run(e *zerolog.Event, level zerolog.Level, msg string) {
+	var txn *newrelic.Transaction
+	if h.Context != nil {
+		txn = newrelic.FromContext(h.Context)
+	}
+
+	logLevel := ""
+	if level == zerolog.NoLevel {
+		logLevel = newrelic.LogSeverityUnknown
+	} else {
+		logLevel = level.String()
+	}
+
+	data := newrelic.LogData{
+		Severity: logLevel,
+		Message:  msg,
+	}
+
+	if txn != nil {
+		txn.RecordLog(data)
+	} else {
+		h.App.RecordLog(data)
+	}
+}

v3/internal/connect_reply.go

@@ -118,6 +118,7 @@ type EventHarvestConfig struct {
 	Limits         struct {
 		TxnEvents    *uint `json:"analytic_event_data,omitempty"`
 		CustomEvents *uint `json:"custom_event_data,omitempty"`
+		LogEvents    *uint `json:"log_event_data,omitempty"`
 		ErrorEvents  *uint `json:"error_event_data,omitempty"`
 		SpanEvents   *uint `json:"span_event_data,omitempty"`
 	} `json:"harvest_limits"`
@@ -136,19 +137,20 @@ func (r *ConnectReply) ConfigurablePeriod() time.Duration {
 func uintPtr(x uint) *uint { return &x }
 
 // DefaultEventHarvestConfig provides faster event harvest defaults.
-func DefaultEventHarvestConfig(maxTxnEvents int) EventHarvestConfig {
+func DefaultEventHarvestConfig(maxTxnEvents, maxLogEvents int) EventHarvestConfig {
 	cfg := EventHarvestConfig{}
 	cfg.ReportPeriodMs = DefaultConfigurableEventHarvestMs
 	cfg.Limits.TxnEvents = uintPtr(uint(maxTxnEvents))
 	cfg.Limits.CustomEvents = uintPtr(uint(MaxCustomEvents))
+	cfg.Limits.LogEvents = uintPtr(uint(maxLogEvents))
 	cfg.Limits.ErrorEvents = uintPtr(uint(MaxErrorEvents))
 	return cfg
 }
 
 // DefaultEventHarvestConfigWithDT is an extended version of DefaultEventHarvestConfig,
 // with the addition that it takes into account distributed tracer span event harvest limits.
-func DefaultEventHarvestConfigWithDT(maxTxnEvents int, dtEnabled bool, spanEventLimit int) EventHarvestConfig {
-	cfg := DefaultEventHarvestConfig(maxTxnEvents)
+func DefaultEventHarvestConfigWithDT(maxTxnEvents, maxLogEvents, spanEventLimit int, dtEnabled bool) EventHarvestConfig {
+	cfg := DefaultEventHarvestConfig(maxTxnEvents, maxLogEvents)
 	if dtEnabled {
 		cfg.Limits.SpanEvents = uintPtr(uint(spanEventLimit))
 	}

v3/internal/connect_reply_test.go

@@ -173,11 +173,13 @@ func TestNegativeHarvestLimits(t *testing.T) {
 }
 
 func TestDefaultEventHarvestConfigJSON(t *testing.T) {
-	js, err := json.Marshal(DefaultEventHarvestConfig(MaxTxnEvents))
+	js, err := json.Marshal(DefaultEventHarvestConfig(MaxTxnEvents, MaxLogEvents))
 	if err != nil {
 		t.Error(err)
 	}
-	if string(js) != `{"report_period_ms":60000,"harvest_limits":{"analytic_event_data":10000,"custom_event_data":10000,"error_event_data":100}}` {
-		t.Error(string(js))
+
+	expect := `{"report_period_ms":60000,"harvest_limits":{"analytic_event_data":10000,"custom_event_data":10000,"log_event_data":10000,"error_event_data":100}}`
+	if string(js) != expect {
+		t.Errorf("DefaultEventHarvestConfig does not match expected valued:\nExpected:\t%s\nActual:\t\t%s", expect, string(js))
 	}
 }

v3/internal/expect.go

@@ -26,6 +26,15 @@ type WantError struct {
 	AgentAttributes map[string]interface{}
 }
 
+// WantLog is a traced log event expectation
+type WantLog struct {
+	Severity  string
+	Message   string
+	SpanID    string
+	TraceID   string
+	Timestamp int64
+}
+
 func uniquePointer() *struct{} {
 	s := struct{}{}
 	return &s
@@ -112,6 +121,7 @@ type WantTxn struct {
 // captured.
 type Expect interface {
 	ExpectCustomEvents(t Validator, want []WantEvent)
+	ExpectLogEvents(t Validator, want []WantLog)
 	ExpectErrors(t Validator, want []WantError)
 	ExpectErrorEvents(t Validator, want []WantEvent)
 

v3/internal/integrationsupport/integrationsupport.go

@@ -93,6 +93,13 @@ var DTEnabledCfgFn = func(cfg *newrelic.Config) {
 	cfg.DistributedTracer.Enabled = true
 }
 
+var AppLogEnabledCfgFn = func(cfg *newrelic.Config) {
+	cfg.Enabled = false
+	cfg.ApplicationLogging.Enabled = true
+	cfg.ApplicationLogging.Forwarding.Enabled = true
+	cfg.ApplicationLogging.Metrics.Enabled = true
+}
+
 // SampleEverythingReplyFn is a reusable ConnectReply function that samples everything
 var SampleEverythingReplyFn = func(reply *internal.ConnectReply) {
 	reply.SetSampleEverything()

v3/internal/jsonx/encode_test.go

@@ -180,3 +180,19 @@ func TestAppendString(t *testing.T) {
 		}
 	}
 }
+
+func BenchmarkAppendString(b *testing.B) {
+	buf := &bytes.Buffer{}
+
+	for i := 0; i < b.N; i++ {
+		AppendString(buf, "s")
+	}
+}
+
+func BenchmarkAppendString10(b *testing.B) {
+	buf := &bytes.Buffer{}
+
+	for i := 0; i < b.N; i++ {
+		AppendString(buf, "qwertyuiop")
+	}
+}

v3/internal/limits.go

@@ -17,6 +17,9 @@ const (
 	// MaxCustomEvents is the maximum number of Transaction Events that can be captured
 	// per 60-second harvest cycle
 	MaxCustomEvents = 10 * 1000
+	// MaxLogEvents is the maximum number of Log Events that can be captured per
+	// 60-second harvest cycle
+	MaxLogEvents = 10 * 1000
 	// MaxTxnEvents is the maximum number of Transaction Events that can be captured
 	// per 60-second harvest cycle
 	MaxTxnEvents = 10 * 1000

v3/newrelic/analytics_events.go

@@ -19,8 +19,8 @@ type analyticsEventHeap []analyticsEvent
 
 type analyticsEvents struct {
 	numSeen        int
-	events         analyticsEventHeap
 	failedHarvests int
+	events         analyticsEventHeap
 }
 
 func (events *analyticsEvents) NumSeen() float64  { return float64(events.numSeen) }