diff --git a/CHANGELOG.md b/CHANGELOG.md index 8a5dc4621..2b84cf296 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,21 @@ +## 3.33.0 +### Added +- Support for Zap Field Attributes +- Updated dependency on csec-go-agent in nrsecurityagent +### Fixed +- Fixed an issue where running containers on AWS would falsely flag Azure Utilization +- Fixed a typo with nrecho-v3 +- Changed nrslog example to use a context driven handler + +These changes increment the affected integration package version numbers to: +- nrsecurityagent v1.3.1 +- nrecho-v3 v1.1.1 +- logcontext-v2/nrslog v1.2.0 +- logcontext-v2/nrzap v1.2.0 + +### Support statement +We use the latest version of the Go language. At minimum, you should be using no version of Go older than what is supported by the Go team themselves. +See the [Go agent EOL Policy](/docs/apm/agents/go-agent/get-started/go-agent-eol-policy) for details about supported versions of the Go agent and third-party components. ## 3.32.0 ### Added * Updates to support for the New Relic security agent to report API endpoints. diff --git a/v3/integrations/logcontext-v2/nrslog/example/main.go b/v3/integrations/logcontext-v2/nrslog/example/main.go index 57a7d11d1..2544fb3b6 100644 --- a/v3/integrations/logcontext-v2/nrslog/example/main.go +++ b/v3/integrations/logcontext-v2/nrslog/example/main.go @@ -1,6 +1,7 @@ package main import ( + "context" "log/slog" "os" "time" @@ -24,12 +25,13 @@ func main() { log.Info("I am a log message") txn := app.StartTransaction("example transaction") - txnLogger := nrslog.WithTransaction(txn, log) - txnLogger.Info("I am a log inside a transaction") + ctx := newrelic.NewContext(context.Background(), txn) + + log.InfoContext(ctx, "I am a log inside a transaction") // pretend to do some work time.Sleep(500 * time.Millisecond) - txnLogger.Warn("Uh oh, something important happened!") + log.Warn("Uh oh, something important happened!") txn.End() log.Info("All Done!") diff --git a/v3/integrations/logcontext-v2/nrzap/example/main.go b/v3/integrations/logcontext-v2/nrzap/example/main.go index fb7912403..84b1f0eda 100644 --- a/v3/integrations/logcontext-v2/nrzap/example/main.go +++ b/v3/integrations/logcontext-v2/nrzap/example/main.go @@ -1,6 +1,7 @@ package main import ( + "errors" "os" "time" @@ -14,7 +15,10 @@ func main() { app, err := newrelic.NewApplication( newrelic.ConfigAppName("nrzerolog example"), newrelic.ConfigInfoLogger(os.Stdout), + newrelic.ConfigDebugLogger(os.Stdout), newrelic.ConfigFromEnvironment(), + // This is enabled by default. if disabled, the attributes will be marshalled at harvest time. + newrelic.ConfigZapAttributesEncoder(false), ) if err != nil { panic(err) @@ -29,16 +33,29 @@ func main() { } backgroundLogger := zap.New(backgroundCore) - backgroundLogger.Info("this is a background log message") + backgroundLogger.Info("this is a background log message with fields test", zap.Any("foo", 3.14)) txn := app.StartTransaction("nrzap example transaction") txnCore, err := nrzap.WrapTransactionCore(core, txn) if err != nil && err != nrzap.ErrNilTxn { panic(err) } - txnLogger := zap.New(txnCore) - txnLogger.Info("this is a transaction log message") + txnLogger.Info("this is a transaction log message with custom fields", + zap.String("zapstring", "region-test-2"), + zap.Int("zapint", 123), + zap.Duration("zapduration", 200*time.Millisecond), + zap.Bool("zapbool", true), + zap.Object("zapobject", zapcore.ObjectMarshalerFunc(func(enc zapcore.ObjectEncoder) error { + enc.AddString("foo", "bar") + return nil + })), + + zap.Any("zapmap", map[string]any{"pi": 3.14, "duration": 2 * time.Second}), + ) + + err = errors.New("OW! an error occurred") + txnLogger.Error("this is an error log message", zap.Error(err)) txn.End() diff --git a/v3/integrations/logcontext-v2/nrzap/nrzap.go b/v3/integrations/logcontext-v2/nrzap/nrzap.go index cf4823f3b..ae5a7ff8f 100644 --- a/v3/integrations/logcontext-v2/nrzap/nrzap.go +++ b/v3/integrations/logcontext-v2/nrzap/nrzap.go @@ -2,6 +2,8 @@ package nrzap import ( "errors" + "math" + "time" "github.com/newrelic/go-agent/v3/internal" "github.com/newrelic/go-agent/v3/newrelic" @@ -24,12 +26,79 @@ type newrelicApplicationState struct { txn *newrelic.Transaction } +// Helper function that converts zap fields to a map of string interface +func convertFieldWithMapEncoder(fields []zap.Field) map[string]interface{} { + attributes := make(map[string]interface{}) + for _, field := range fields { + enc := zapcore.NewMapObjectEncoder() + field.AddTo(enc) + for key, value := range enc.Fields { + // Format time.Duration values as strings + if durationVal, ok := value.(time.Duration); ok { + attributes[key] = durationVal.String() + } else { + attributes[key] = value + } + } + } + return attributes +} + +func convertFieldsAtHarvestTime(fields []zap.Field) map[string]interface{} { + attributes := make(map[string]interface{}) + for _, field := range fields { + if field.Interface != nil { + + // Handles ErrorType fields + if field.Type == zapcore.ErrorType { + attributes[field.Key] = field.Interface.(error).Error() + } else { + // Handles all interface types + attributes[field.Key] = field.Interface + } + + } else if field.String != "" { // Check if the field is a string and doesn't contain an interface + attributes[field.Key] = field.String + + } else { + // Float Types + if field.Type == zapcore.Float32Type { + attributes[field.Key] = math.Float32frombits(uint32(field.Integer)) + continue + } else if field.Type == zapcore.Float64Type { + attributes[field.Key] = math.Float64frombits(uint64(field.Integer)) + continue + } + // Bool Type + if field.Type == zapcore.BoolType { + field.Interface = field.Integer == 1 + attributes[field.Key] = field.Interface + } else { + // Integer Types + attributes[field.Key] = field.Integer + + } + } + } + return attributes +} + // internal handler function to manage writing a log to the new relic application func (nr *newrelicApplicationState) recordLog(entry zapcore.Entry, fields []zap.Field) { + attributes := map[string]interface{}{} + cfg, _ := nr.app.Config() + + // Check if the attributes should be frontloaded or marshalled at harvest time + if cfg.ApplicationLogging.ZapLogger.AttributesFrontloaded { + attributes = convertFieldWithMapEncoder(fields) + } else { + attributes = convertFieldsAtHarvestTime(fields) + } data := newrelic.LogData{ - Timestamp: entry.Time.UnixMilli(), - Severity: entry.Level.String(), - Message: entry.Message, + Timestamp: entry.Time.UnixMilli(), + Severity: entry.Level.String(), + Message: entry.Message, + Attributes: attributes, } if nr.txn != nil { diff --git a/v3/integrations/logcontext-v2/nrzap/nrzap_test.go b/v3/integrations/logcontext-v2/nrzap/nrzap_test.go index 33adfcd26..34100166b 100644 --- a/v3/integrations/logcontext-v2/nrzap/nrzap_test.go +++ b/v3/integrations/logcontext-v2/nrzap/nrzap_test.go @@ -5,6 +5,7 @@ import ( "io" "os" "testing" + "time" "github.com/newrelic/go-agent/v3/internal" "github.com/newrelic/go-agent/v3/internal/integrationsupport" @@ -131,6 +132,9 @@ func TestTransactionLogger(t *testing.T) { app.ExpectLogEvents(t, []internal.WantLog{ { + Attributes: map[string]interface{}{ + "test-key": "test-val", + }, Severity: zap.ErrorLevel.String(), Message: msg, Timestamp: internal.MatchAnyUnixMilli, @@ -140,6 +144,110 @@ func TestTransactionLogger(t *testing.T) { }) } +func TestTransactionLoggerWithFields(t *testing.T) { + app := integrationsupport.NewTestApp(integrationsupport.SampleEverythingReplyFn, + newrelic.ConfigAppLogDecoratingEnabled(true), + newrelic.ConfigAppLogForwardingEnabled(true), + newrelic.ConfigZapAttributesEncoder(true), + ) + + txn := app.StartTransaction("test transaction") + txnMetadata := txn.GetTraceMetadata() + + core := zapcore.NewCore(zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()), os.Stdout, zap.InfoLevel) + wrappedCore, err := WrapTransactionCore(core, txn) + if err != nil { + t.Error(err) + } + + logger := zap.New(wrappedCore) + + msg := "this is a test info message" + + // for background logging: + logger.Info(msg, + zap.String("region", "region-test-2"), + zap.Any("anyValue", map[string]interface{}{"pi": 3.14, "duration": 2 * time.Second}), + zap.Duration("duration", 1*time.Second), + zap.Int("int", 123), + zap.Bool("bool", true), + ) + + logger.Sync() + + // ensure txn gets written to an event and logs get released + txn.End() + + app.ExpectLogEvents(t, []internal.WantLog{ + { + Attributes: map[string]interface{}{ + "region": "region-test-2", + "anyValue": map[string]interface{}{"pi": 3.14, "duration": 2 * time.Second}, + "duration": 1 * time.Second, + "int": 123, + "bool": true, + }, + Severity: zap.InfoLevel.String(), + Message: msg, + Timestamp: internal.MatchAnyUnixMilli, + TraceID: txnMetadata.TraceID, + SpanID: txnMetadata.SpanID, + }, + }) +} + +func TestTransactionLoggerWithFieldsAtHarvestTime(t *testing.T) { + app := integrationsupport.NewTestApp(integrationsupport.SampleEverythingReplyFn, + newrelic.ConfigAppLogDecoratingEnabled(true), + newrelic.ConfigAppLogForwardingEnabled(true), + newrelic.ConfigZapAttributesEncoder(false), + ) + + txn := app.StartTransaction("test transaction") + txnMetadata := txn.GetTraceMetadata() + + core := zapcore.NewCore(zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()), os.Stdout, zap.InfoLevel) + wrappedCore, err := WrapTransactionCore(core, txn) + if err != nil { + t.Error(err) + } + + logger := zap.New(wrappedCore) + + msg := "this is a test info message" + + // for background logging: + logger.Info(msg, + zap.String("region", "region-test-2"), + zap.Any("anyValue", map[string]interface{}{"pi": 3.14, "duration": 2 * time.Second}), + zap.Duration("duration", 1*time.Second), + zap.Int("int", 123), + zap.Bool("bool", true), + ) + + logger.Sync() + + // ensure txn gets written to an event and logs get released + txn.End() + + app.ExpectLogEvents(t, []internal.WantLog{ + { + Attributes: map[string]interface{}{ + "region": "region-test-2", + "anyValue": map[string]interface{}{"pi": 3.14, "duration": 2 * time.Second}, + "duration": 1 * time.Second, + "int": 123, + "bool": true, + }, + Severity: zap.InfoLevel.String(), + Message: msg, + Timestamp: internal.MatchAnyUnixMilli, + TraceID: txnMetadata.TraceID, + SpanID: txnMetadata.SpanID, + }, + }) +} + func TestTransactionLoggerNilTxn(t *testing.T) { app := integrationsupport.NewTestApp(integrationsupport.SampleEverythingReplyFn, newrelic.ConfigAppLogDecoratingEnabled(true), @@ -204,6 +312,41 @@ func BenchmarkZapBaseline(b *testing.B) { } } +func BenchmarkFieldConversion(b *testing.B) { + b.ResetTimer() + b.ReportAllocs() + + for i := 0; i < b.N; i++ { + convertFieldWithMapEncoder([]zap.Field{ + zap.String("test-key", "test-val"), + zap.Any("test-key", map[string]interface{}{"pi": 3.14, "duration": 2 * time.Second}), + }) + } +} + +func BenchmarkFieldUnmarshalling(b *testing.B) { + b.ResetTimer() + b.ReportAllocs() + for i := 0; i < b.N; i++ { + convertFieldsAtHarvestTime([]zap.Field{ + zap.String("test-key", "test-val"), + zap.Any("test-key", map[string]interface{}{"pi": 3.14, "duration": 2 * time.Second}), + }) + + } +} + +func BenchmarkZapWithAttribute(b *testing.B) { + core := zapcore.NewCore(zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()), zapcore.AddSync(io.Discard), zap.InfoLevel) + logger := zap.New(core) + b.ResetTimer() + b.ReportAllocs() + + for i := 0; i < b.N; i++ { + logger.Info("this is a test message", zap.Any("test-key", "test-val")) + } +} + func BenchmarkZapWrappedCore(b *testing.B) { app := integrationsupport.NewTestApp(integrationsupport.SampleEverythingReplyFn, newrelic.ConfigAppLogDecoratingEnabled(true), diff --git a/v3/integrations/nrecho-v3/nrecho.go b/v3/integrations/nrecho-v3/nrecho.go index 9fe29f54b..06de72784 100644 --- a/v3/integrations/nrecho-v3/nrecho.go +++ b/v3/integrations/nrecho-v3/nrecho.go @@ -35,6 +35,22 @@ func handlerPointer(handler echo.HandlerFunc) uintptr { return reflect.ValueOf(handler).Pointer() } +func handlerName(router interface{}) string { + val := reflect.ValueOf(router) + if val.Kind() == reflect.Ptr { // for echo version v3.2.2+ + val = val.Elem() + } else { + val = reflect.ValueOf(&router).Elem().Elem() + } + if name := val.FieldByName("Name"); name.IsValid() { // for echo version v3.2.2+ + return name.String() + } else if handler := val.FieldByName("Handler"); handler.IsValid() { + return handler.String() + } else { + return "" + } +} + func transactionName(c echo.Context) string { ptr := handlerPointer(c.Handler()) if ptr == handlerPointer(echo.NotFoundHandler) { @@ -108,7 +124,7 @@ func WrapRouter(engine *echo.Echo) { if engine != nil && newrelic.IsSecurityAgentPresent() { router := engine.Routes() for _, r := range router { - newrelic.GetSecurityAgentInterface().SendEvent("API_END_POINTS", r.Path, r.Method, r.Handler) + newrelic.GetSecurityAgentInterface().SendEvent("API_END_POINTS", r.Path, r.Method, handlerName(r)) } } } diff --git a/v3/integrations/nrsecurityagent/go.mod b/v3/integrations/nrsecurityagent/go.mod index 321e774b6..78f9814bc 100644 --- a/v3/integrations/nrsecurityagent/go.mod +++ b/v3/integrations/nrsecurityagent/go.mod @@ -3,7 +3,7 @@ module github.com/newrelic/go-agent/v3/integrations/nrsecurityagent go 1.20 require ( - github.com/newrelic/csec-go-agent v1.1.0 + github.com/newrelic/csec-go-agent v1.2.0 github.com/newrelic/go-agent/v3 v3.32.0 github.com/newrelic/go-agent/v3/integrations/nrsqlite3 v1.2.0 gopkg.in/yaml.v2 v2.4.0 diff --git a/v3/internal/expect.go b/v3/internal/expect.go index edb92bdc2..6ed3d4f46 100644 --- a/v3/internal/expect.go +++ b/v3/internal/expect.go @@ -29,11 +29,12 @@ type WantError struct { // WantLog is a traced log event expectation type WantLog struct { - Severity string - Message string - SpanID string - TraceID string - Timestamp int64 + Attributes map[string]interface{} + Severity string + Message string + SpanID string + TraceID string + Timestamp int64 } func uniquePointer() *struct{} { diff --git a/v3/internal/utilization/azure.go b/v3/internal/utilization/azure.go index b2e1846be..5a747e2c1 100644 --- a/v3/internal/utilization/azure.go +++ b/v3/internal/utilization/azure.go @@ -28,7 +28,9 @@ func gatherAzure(util *Data, client *http.Client) error { if err != nil { // Only return the error here if it is unexpected to prevent // warning customers who aren't running Azure about a timeout. - if _, ok := err.(unexpectedAzureErr); ok { + // If any of the other vendors have already been detected and set, and we have an error, we should not return the error + // If no vendors have been detected, we should return the error. + if _, ok := err.(unexpectedAzureErr); ok && !util.Vendors.AnySet() { return err } return nil diff --git a/v3/internal/utilization/utilization.go b/v3/internal/utilization/utilization.go index ad2a4ea5d..e9b5085d6 100644 --- a/v3/internal/utilization/utilization.go +++ b/v3/internal/utilization/utilization.go @@ -3,7 +3,6 @@ // Package utilization implements the Utilization spec, available at // https://source.datanerd.us/agents/agent-specs/blob/master/Utilization.md -// package utilization import ( @@ -84,6 +83,9 @@ type vendors struct { Kubernetes *kubernetes `json:"kubernetes,omitempty"` } +func (v *vendors) AnySet() bool { + return v.AWS != nil || v.Azure != nil || v.GCP != nil || v.PCF != nil || v.Docker != nil || v.Kubernetes != nil +} func (v *vendors) isEmpty() bool { return nil == v || *v == vendors{} } diff --git a/v3/newrelic/attributes_from_internal.go b/v3/newrelic/attributes_from_internal.go index fca46d9cf..430c5752a 100644 --- a/v3/newrelic/attributes_from_internal.go +++ b/v3/newrelic/attributes_from_internal.go @@ -5,10 +5,12 @@ package newrelic import ( "bytes" + "encoding/json" "fmt" "math" "net/http" "net/url" + "reflect" "sort" "strconv" "strings" @@ -19,6 +21,9 @@ const ( // listed as span attributes to simplify code. It is not listed in the // public attributes.go file for this reason to prevent confusion. spanAttributeQueryParameters = "query_parameters" + + // The collector can only allow attributes to be a maximum of 256 bytes + maxAttributeLengthBytes = 256 ) var ( @@ -452,6 +457,9 @@ func addUserAttribute(a *attributes, key string, val interface{}, d destinationS func writeAttributeValueJSON(w *jsonFieldsWriter, key string, val interface{}) { switch v := val.(type) { case string: + if len(v) > maxAttributeLengthBytes { + v = v[:maxAttributeLengthBytes] + } w.stringField(key, v) case bool: if v { @@ -486,7 +494,17 @@ func writeAttributeValueJSON(w *jsonFieldsWriter, key string, val interface{}) { case float64: w.floatField(key, v) default: - w.stringField(key, fmt.Sprintf("%T", v)) + // attempt to construct a JSON string + kind := reflect.ValueOf(v).Kind() + if kind == reflect.Struct || kind == reflect.Map || kind == reflect.Slice || kind == reflect.Array { + bytes, _ := json.Marshal(v) + if len(bytes) > maxAttributeLengthBytes { + bytes = bytes[:maxAttributeLengthBytes] + } + w.stringField(key, string(bytes)) + } else { + w.stringField(key, fmt.Sprintf("%T", v)) + } } } diff --git a/v3/newrelic/config.go b/v3/newrelic/config.go index d0461ca1c..b34537d68 100644 --- a/v3/newrelic/config.go +++ b/v3/newrelic/config.go @@ -582,6 +582,15 @@ type ApplicationLogging struct { // Toggles whether the agent enriches local logs printed to console so they can be sent to new relic for ingestion Enabled bool } + // We want to enable this when your app collects fewer logs, or if your app can afford to compile the json + // during log collection, slowing down the execution of the line of code that will write the log. If your + // application collects logs at a high frequency or volume, or it can not afford the slowdown of marshaling objects + // before sending them to new relic, we can marshal them asynchronously in the backend during harvests by setting + // this to false using ConfigZapAttributesEncoder(false). + ZapLogger struct { + // Toggles whether zap logger field attributes are frontloaded with the zapcore.NewMapObjectEncoder or marshalled at harvest time + AttributesFrontloaded bool + } } // AttributeDestinationConfig controls the attributes sent to each destination. @@ -654,7 +663,7 @@ func defaultConfig() Config { c.ApplicationLogging.Forwarding.MaxSamplesStored = internal.MaxLogEvents c.ApplicationLogging.Metrics.Enabled = true c.ApplicationLogging.LocalDecorating.Enabled = false - + c.ApplicationLogging.ZapLogger.AttributesFrontloaded = true c.BrowserMonitoring.Enabled = true // browser monitoring attributes are disabled by default c.BrowserMonitoring.Attributes.Enabled = false diff --git a/v3/newrelic/config_options.go b/v3/newrelic/config_options.go index 082b46d83..8c3daf6f7 100644 --- a/v3/newrelic/config_options.go +++ b/v3/newrelic/config_options.go @@ -302,6 +302,13 @@ func ConfigInfoLogger(w io.Writer) ConfigOption { return ConfigLogger(NewLogger(w)) } +// ConfigZapAttributesEncoder controls whether the agent will frontload the zap logger field attributes with the zapcore.NewMapObjectEncoder or marshal at harvest time +func ConfigZapAttributesEncoder(enabled bool) ConfigOption { + return func(cfg *Config) { + cfg.ApplicationLogging.ZapLogger.AttributesFrontloaded = enabled + } +} + // ConfigModuleDependencyMetricsEnabled controls whether the agent collects and reports // the list of modules compiled into the instrumented application. func ConfigModuleDependencyMetricsEnabled(enabled bool) ConfigOption { diff --git a/v3/newrelic/config_test.go b/v3/newrelic/config_test.go index 9400a4e20..6ce06a6e6 100644 --- a/v3/newrelic/config_test.go +++ b/v3/newrelic/config_test.go @@ -151,6 +151,9 @@ func TestCopyConfigReferenceFieldsPresent(t *testing.T) { }, "Metrics": { "Enabled": true + }, + "ZapLogger": { + "AttributesFrontloaded": true } }, "Attributes":{"Enabled":true,"Exclude":["2"],"Include":["1"]}, @@ -356,6 +359,9 @@ func TestCopyConfigReferenceFieldsAbsent(t *testing.T) { }, "Metrics": { "Enabled": true + }, + "ZapLogger": { + "AttributesFrontloaded": true } }, "Attributes":{"Enabled":true,"Exclude":null,"Include":null}, diff --git a/v3/newrelic/expect_implementation.go b/v3/newrelic/expect_implementation.go index 970ad4d07..122d588ff 100644 --- a/v3/newrelic/expect_implementation.go +++ b/v3/newrelic/expect_implementation.go @@ -249,8 +249,75 @@ func expectLogEvent(v internal.Validator, actual logEvent, want internal.WantLog v.Error(fmt.Sprintf("unexpected log timestamp: got %d, want %d", actual.timestamp, want.Timestamp)) return } + + if actual.attributes != nil && want.Attributes != nil { + for k, val := range want.Attributes { + actualVal, actualOk := actual.attributes[k] + if !actualOk { + v.Error(fmt.Sprintf("expected log attribute for key %v is missing", k)) + return + } + + // Check if both values are maps, and if so, compare them recursively + if expectedMap, ok := val.(map[string]interface{}); ok { + if actualMap, ok := actualVal.(map[string]interface{}); ok { + if !expectLogEventAttributesMaps(expectedMap, actualMap) { + v.Error(fmt.Sprintf("unexpected log attribute for key %v: got %v, want %v", k, actualMap, expectedMap)) + return + } + } else { + v.Error(fmt.Sprintf("actual value for key %v is not a map", k)) + return + } + } + } + } + } +// Helper function that compares two maps for equality. This is used to compare the attribute fields of log events expected vs received +func expectLogEventAttributesMaps(a, b map[string]interface{}) bool { + if len(a) != len(b) { + return false + } + for k, v := range a { + if bv, ok := b[k]; !ok { + return false + } else { + switch v := v.(type) { + case float64: + if bv, ok := bv.(float64); !ok || v != bv { + return false + } + + case int: + if bv, ok := bv.(int); !ok || v != bv { + return false + } + case time.Duration: + if bv, ok := bv.(time.Duration); ok { + return v == bv + } + case string: + if bv, ok := bv.(string); !ok || v != bv { + return false + } + case int64: + if bv, ok := bv.(int64); !ok || v != bv { + return false + } + // if the type of the field is a map, recursively compare the maps + case map[string]interface{}: + if bv, ok := bv.(map[string]interface{}); !ok || !expectLogEventAttributesMaps(v, bv) { + return false + } + default: + return false + } + } + } + return true +} func expectEvent(v internal.Validator, e json.Marshaler, expect internal.WantEvent) { js, err := e.MarshalJSON() if nil != err { diff --git a/v3/newrelic/harvest_test.go b/v3/newrelic/harvest_test.go index 73fdd9b71..9e9f00314 100644 --- a/v3/newrelic/harvest_test.go +++ b/v3/newrelic/harvest_test.go @@ -315,6 +315,7 @@ func TestHarvestLogEventsReady(t *testing.T) { }) logEvent := logEvent{ + nil, 0.5, 123456, "INFO", @@ -576,6 +577,7 @@ func TestMergeFailedHarvest(t *testing.T) { }, 0) logEvent := logEvent{ + nil, 0.5, 123456, "INFO", diff --git a/v3/newrelic/log_event.go b/v3/newrelic/log_event.go index 5fd705ef0..700be9d24 100644 --- a/v3/newrelic/log_event.go +++ b/v3/newrelic/log_event.go @@ -19,19 +19,25 @@ const ( ) type logEvent struct { - priority priority - timestamp int64 - severity string - message string - spanID string - traceID string + attributes map[string]any + priority priority + timestamp int64 + severity string + message string + spanID string + traceID string } // LogData contains data fields that are needed to generate log events. +// Note: if you are passing a struct, map, slice, or array as an attribute, try to pass it as a JSON string generated by the logging framework if possible. +// The collector can parse that into an object on New Relic's side. +// This is preferable because the json.Marshal method used in the agent to create the string log JSON is usually less efficient than the tools built into +// logging products for creating stringified JSON for complex objects and data structures. type LogData struct { - Timestamp int64 // Optional: Unix Millisecond Timestamp; A timestamp will be generated if unset - Severity string // Optional: Severity of log being consumed - Message string // Optional: Message of log being consumed; Maximum size: 32768 Bytes. + Timestamp int64 // Optional: Unix Millisecond Timestamp; A timestamp will be generated if unset + Severity string // Optional: Severity of log being consumed + Message string // Optional: Message of log being consumed; Maximum size: 32768 Bytes. + Attributes map[string]any // Optional: a key value pair with a string key, and any value. This can be used for categorizing logs in the UI. } // writeJSON prepares JSON in the format expected by the collector. @@ -51,6 +57,14 @@ func (e *logEvent) WriteJSON(buf *bytes.Buffer) { w.needsComma = false buf.WriteByte(',') w.intField(logcontext.LogTimestampFieldName, e.timestamp) + if e.attributes != nil && len(e.attributes) > 0 { + buf.WriteString(`,"attributes":{`) + w := jsonFieldsWriter{buf: buf} + for key, val := range e.attributes { + writeAttributeValueJSON(&w, key, val) + } + buf.WriteByte('}') + } buf.WriteByte('}') } @@ -84,10 +98,11 @@ func (data *LogData) toLogEvent() (logEvent, error) { data.Severity = strings.TrimSpace(data.Severity) event := logEvent{ - priority: newPriority(), - message: data.Message, - severity: data.Severity, - timestamp: data.Timestamp, + priority: newPriority(), + message: data.Message, + severity: data.Severity, + timestamp: data.Timestamp, + attributes: data.Attributes, } return event, nil diff --git a/v3/newrelic/log_events.go b/v3/newrelic/log_events.go index c02b76058..df3861570 100644 --- a/v3/newrelic/log_events.go +++ b/v3/newrelic/log_events.go @@ -60,7 +60,7 @@ type logEventHeap []logEvent // TODO: when go 1.18 becomes the minimum supported version, re-write to make a generic heap implementation // for all event heaps, to de-duplicate this code -//func (events *logEvents) +// func (events *logEvents) func (h logEventHeap) Len() int { return len(h) } func (h logEventHeap) Less(i, j int) bool { return h[i].priority.isLowerPriority(h[j].priority) } func (h logEventHeap) Swap(i, j int) { h[i], h[j] = h[j], h[i] } diff --git a/v3/newrelic/log_events_test.go b/v3/newrelic/log_events_test.go index 2a796d06a..e359ef55a 100644 --- a/v3/newrelic/log_events_test.go +++ b/v3/newrelic/log_events_test.go @@ -36,19 +36,20 @@ func loggingConfigEnabled(limit int) loggingConfig { } } -func sampleLogEvent(priority priority, severity, message string) *logEvent { +func sampleLogEvent(priority priority, severity, message string, attributes map[string]any) *logEvent { return &logEvent{ - priority: priority, - severity: severity, - message: message, - timestamp: 123456, + priority: priority, + severity: severity, + message: message, + attributes: attributes, + timestamp: 123456, } } func TestBasicLogEvents(t *testing.T) { events := newLogEvents(testCommonAttributes, loggingConfigEnabled(5)) - events.Add(sampleLogEvent(0.5, infoLevel, "message1")) - events.Add(sampleLogEvent(0.5, infoLevel, "message2")) + events.Add(sampleLogEvent(0.5, infoLevel, "message1", nil)) + events.Add(sampleLogEvent(0.5, infoLevel, "message2", nil)) json, err := events.CollectorJSON(agentRunID) if nil != err { @@ -70,6 +71,53 @@ func TestBasicLogEvents(t *testing.T) { } } +type testStruct struct { + A string + B int + C c +} + +type c struct { + D string +} + +func TestBasicLogEventWithAttributes(t *testing.T) { + st := testStruct{ + A: "a", + B: 1, + C: c{"hello"}, + } + + events := newLogEvents(testCommonAttributes, loggingConfigEnabled(5)) + events.Add(sampleLogEvent(0.5, infoLevel, "message1", map[string]any{"two": "hi"})) + events.Add(sampleLogEvent(0.5, infoLevel, "message2", map[string]any{"struct": st})) + events.Add(sampleLogEvent(0.5, infoLevel, "message3", map[string]any{"map": map[string]string{"hi": "hello"}})) + events.Add(sampleLogEvent(0.5, infoLevel, "message4", map[string]any{"slice": []string{"hi", "hello", "test"}})) + events.Add(sampleLogEvent(0.5, infoLevel, "message5", map[string]any{"array": [2]int{1, 2}})) + + json, err := events.CollectorJSON(agentRunID) + if nil != err { + t.Fatal(err) + } + + expected := commonJSON + + `{"level":"INFO","message":"message1","timestamp":123456,"attributes":{"two":"hi"}},` + + `{"level":"INFO","message":"message2","timestamp":123456,"attributes":{"struct":"{\"A\":\"a\",\"B\":1,\"C\":{\"D\":\"hello\"}}"}},` + + `{"level":"INFO","message":"message3","timestamp":123456,"attributes":{"map":"{\"hi\":\"hello\"}"}},` + + `{"level":"INFO","message":"message4","timestamp":123456,"attributes":{"slice":"[\"hi\",\"hello\",\"test\"]"}},` + + `{"level":"INFO","message":"message5","timestamp":123456,"attributes":{"array":"[1,2]"}}]}]` + + if string(json) != expected { + t.Error("actual not equal to expected:\n", string(json), "\n", expected) + } + if events.numSeen != 5 { + t.Error(events.numSeen) + } + if events.NumSaved() != 5 { + t.Error(events.NumSaved()) + } +} + func TestEmptyLogEvents(t *testing.T) { events := newLogEvents(testCommonAttributes, loggingConfigEnabled(10)) json, err := events.CollectorJSON(agentRunID) @@ -79,10 +127,10 @@ func TestEmptyLogEvents(t *testing.T) { if nil != json { t.Error(string(json)) } - if 0 != events.numSeen { + if events.numSeen != 0 { t.Error(events.numSeen) } - if 0 != events.NumSaved() { + if events.NumSaved() != 0 { t.Error(events.NumSaved()) } } @@ -91,12 +139,12 @@ func TestEmptyLogEvents(t *testing.T) { func TestSamplingLogEvents(t *testing.T) { events := newLogEvents(testCommonAttributes, loggingConfigEnabled(3)) - events.Add(sampleLogEvent(0.999999, infoLevel, "a")) - events.Add(sampleLogEvent(0.1, infoLevel, "b")) - events.Add(sampleLogEvent(0.9, infoLevel, "c")) - events.Add(sampleLogEvent(0.2, infoLevel, "d")) - events.Add(sampleLogEvent(0.8, infoLevel, "e")) - events.Add(sampleLogEvent(0.3, infoLevel, "f")) + events.Add(sampleLogEvent(0.999999, infoLevel, "a", nil)) + events.Add(sampleLogEvent(0.1, infoLevel, "b", nil)) + events.Add(sampleLogEvent(0.9, infoLevel, "c", nil)) + events.Add(sampleLogEvent(0.2, infoLevel, "d", nil)) + events.Add(sampleLogEvent(0.8, infoLevel, "e", nil)) + events.Add(sampleLogEvent(0.3, infoLevel, "f", nil)) json, err := events.CollectorJSON(agentRunID) if nil != err { @@ -141,14 +189,14 @@ func TestMergeFullLogEvents(t *testing.T) { e1 := newLogEvents(testCommonAttributes, loggingConfigEnabled(2)) e2 := newLogEvents(testCommonAttributes, loggingConfigEnabled(3)) - e1.Add(sampleLogEvent(0.1, infoLevel, "a")) - e1.Add(sampleLogEvent(0.15, infoLevel, "b")) - e1.Add(sampleLogEvent(0.25, infoLevel, "c")) + e1.Add(sampleLogEvent(0.1, infoLevel, "a", nil)) + e1.Add(sampleLogEvent(0.15, infoLevel, "b", nil)) + e1.Add(sampleLogEvent(0.25, infoLevel, "c", nil)) - e2.Add(sampleLogEvent(0.06, infoLevel, "d")) - e2.Add(sampleLogEvent(0.12, infoLevel, "e")) - e2.Add(sampleLogEvent(0.18, infoLevel, "f")) - e2.Add(sampleLogEvent(0.24, infoLevel, "g")) + e2.Add(sampleLogEvent(0.06, infoLevel, "d", nil)) + e2.Add(sampleLogEvent(0.12, infoLevel, "e", nil)) + e2.Add(sampleLogEvent(0.18, infoLevel, "f", nil)) + e2.Add(sampleLogEvent(0.24, infoLevel, "g", nil)) e1.Merge(e2) json, err := e1.CollectorJSON(agentRunID) @@ -176,14 +224,14 @@ func TestLogEventMergeFailedSuccess(t *testing.T) { e1 := newLogEvents(testCommonAttributes, loggingConfigEnabled(2)) e2 := newLogEvents(testCommonAttributes, loggingConfigEnabled(3)) - e1.Add(sampleLogEvent(0.1, infoLevel, "a")) - e1.Add(sampleLogEvent(0.15, infoLevel, "b")) - e1.Add(sampleLogEvent(0.25, infoLevel, "c")) + e1.Add(sampleLogEvent(0.1, infoLevel, "a", nil)) + e1.Add(sampleLogEvent(0.15, infoLevel, "b", nil)) + e1.Add(sampleLogEvent(0.25, infoLevel, "c", nil)) - e2.Add(sampleLogEvent(0.06, infoLevel, "d")) - e2.Add(sampleLogEvent(0.12, infoLevel, "e")) - e2.Add(sampleLogEvent(0.18, infoLevel, "f")) - e2.Add(sampleLogEvent(0.24, infoLevel, "g")) + e2.Add(sampleLogEvent(0.06, infoLevel, "d", nil)) + e2.Add(sampleLogEvent(0.12, infoLevel, "e", nil)) + e2.Add(sampleLogEvent(0.18, infoLevel, "f", nil)) + e2.Add(sampleLogEvent(0.24, infoLevel, "g", nil)) e1.mergeFailed(e2) @@ -214,14 +262,14 @@ func TestLogEventMergeFailedLimitReached(t *testing.T) { e1 := newLogEvents(testCommonAttributes, loggingConfigEnabled(2)) e2 := newLogEvents(testCommonAttributes, loggingConfigEnabled(3)) - e1.Add(sampleLogEvent(0.1, infoLevel, "a")) - e1.Add(sampleLogEvent(0.15, infoLevel, "b")) - e1.Add(sampleLogEvent(0.25, infoLevel, "c")) + e1.Add(sampleLogEvent(0.1, infoLevel, "a", nil)) + e1.Add(sampleLogEvent(0.15, infoLevel, "b", nil)) + e1.Add(sampleLogEvent(0.25, infoLevel, "c", nil)) - e2.Add(sampleLogEvent(0.06, infoLevel, "d")) - e2.Add(sampleLogEvent(0.12, infoLevel, "e")) - e2.Add(sampleLogEvent(0.18, infoLevel, "f")) - e2.Add(sampleLogEvent(0.24, infoLevel, "g")) + e2.Add(sampleLogEvent(0.06, infoLevel, "d", nil)) + e2.Add(sampleLogEvent(0.12, infoLevel, "e", nil)) + e2.Add(sampleLogEvent(0.18, infoLevel, "f", nil)) + e2.Add(sampleLogEvent(0.24, infoLevel, "g", nil)) e2.failedHarvests = failedEventsAttemptsLimit @@ -253,7 +301,7 @@ func TestLogEventsSplitFull(t *testing.T) { events := newLogEvents(testCommonAttributes, loggingConfigEnabled(10)) for i := 0; i < 15; i++ { priority := priority(float32(i) / 10.0) - events.Add(sampleLogEvent(priority, "INFO", fmt.Sprint(priority))) + events.Add(sampleLogEvent(priority, "INFO", fmt.Sprint(priority), nil)) } // Test that the capacity cannot exceed the max. if 10 != events.capacity() { @@ -292,7 +340,7 @@ func TestLogEventsSplitNotFullOdd(t *testing.T) { events := newLogEvents(testCommonAttributes, loggingConfigEnabled(10)) for i := 0; i < 7; i++ { priority := priority(float32(i) / 10.0) - events.Add(sampleLogEvent(priority, "INFO", fmt.Sprint(priority))) + events.Add(sampleLogEvent(priority, "INFO", fmt.Sprint(priority), nil)) } e1, e2 := events.split() j1, err1 := e1.CollectorJSON(agentRunID) @@ -322,7 +370,7 @@ func TestLogEventsSplitNotFullEven(t *testing.T) { events := newLogEvents(testCommonAttributes, loggingConfigEnabled(10)) for i := 0; i < 8; i++ { priority := priority(float32(i) / 10.0) - events.Add(sampleLogEvent(priority, "INFO", fmt.Sprint(priority))) + events.Add(sampleLogEvent(priority, "INFO", fmt.Sprint(priority), nil)) } e1, e2 := events.split() j1, err1 := e1.CollectorJSON(agentRunID) @@ -356,7 +404,7 @@ func TestLogEventsZeroCapacity(t *testing.T) { if 0 != events.NumSeen() || 0 != events.NumSaved() || 0 != events.capacity() { t.Error(events.NumSeen(), events.NumSaved(), events.capacity()) } - events.Add(sampleLogEvent(0.5, "INFO", "TEST")) + events.Add(sampleLogEvent(0.5, "INFO", "TEST", nil)) if 1 != events.NumSeen() || 0 != events.NumSaved() || 0 != events.capacity() { t.Error(events.NumSeen(), events.NumSaved(), events.capacity()) } @@ -375,7 +423,7 @@ func TestLogEventCollectionDisabled(t *testing.T) { if 0 != events.NumSeen() || 0 != len(events.severityCount) || 0 != events.NumSaved() || 5 != events.capacity() { t.Error(events.NumSeen(), len(events.severityCount), events.NumSaved(), events.capacity()) } - events.Add(sampleLogEvent(0.5, "INFO", "TEST")) + events.Add(sampleLogEvent(0.5, "INFO", "TEST", nil)) if 1 != events.NumSeen() || 1 != len(events.severityCount) || 0 != events.NumSaved() || 5 != events.capacity() { t.Error(events.NumSeen(), len(events.severityCount), events.NumSaved(), events.capacity()) } @@ -467,6 +515,7 @@ func BenchmarkRecordLoggingMetrics(b *testing.B) { for i := 0; i < internal.MaxLogEvents; i++ { logEvent := logEvent{ + nil, newPriority(), 123456, "INFO", diff --git a/v3/newrelic/version.go b/v3/newrelic/version.go index 53df4c5bd..7630ad141 100644 --- a/v3/newrelic/version.go +++ b/v3/newrelic/version.go @@ -11,7 +11,7 @@ import ( const ( // Version is the full string version of this Go Agent. - Version = "3.32.0" + Version = "3.33.0" ) var (