From 19a8e6172b4096375bd90ca1bbf102b64523f6c2 Mon Sep 17 00:00:00 2001 From: Peter Wiese Date: Fri, 4 Aug 2023 12:27:44 -0700 Subject: [PATCH 1/2] [exporter/azuremonitor] Log exporter handle non-string values The exporter was incorrectly assuming a string value for the body. Minor refactoring of the log exporter unit tests for better isolation. --- .chloggen/exporter_azuremonitor_log-bug.yaml | 27 ++++ .../azuremonitorexporter/log_to_envelope.go | 2 +- .../azuremonitorexporter/logexporter_test.go | 129 ++++++++++++------ 3 files changed, 118 insertions(+), 40 deletions(-) create mode 100755 .chloggen/exporter_azuremonitor_log-bug.yaml diff --git a/.chloggen/exporter_azuremonitor_log-bug.yaml b/.chloggen/exporter_azuremonitor_log-bug.yaml new file mode 100755 index 000000000000..74aa68d9c4ca --- /dev/null +++ b/.chloggen/exporter_azuremonitor_log-bug.yaml @@ -0,0 +1,27 @@ +# Use this changelog template to create an entry for release notes. + +# One of 'breaking', 'deprecation', 'new_component', 'enhancement', 'bug_fix' +change_type: bug_fix + +# The name of the component, or a single word describing the area of concern, (e.g. filelogreceiver) +component: azuremonitor_logexporter + +# A brief description of the change. Surround your text with quotes ("") if it needs to start with a backtick (`). +note: The log exporter now supports non-string data for the log record body. + +# Mandatory: One or more tracking issues related to the change. You can use the PR number here if no issue exists. +issues: [23422] + +# (Optional) One or more lines of additional information to render under the primary note. +# These lines will be padded with 2 spaces and then inserted directly into the document. +# Use pipe (|) for multiline entries. +subtext: + +# If your change doesn't affect end users or the exported elements of any package, +# you should instead start your pull request title with [chore] or use the "Skip Changelog" label. +# Optional: The change log or logs in which this entry should be included. +# e.g. '[user]' or '[user, api]' +# Include 'user' if the change is relevant to end users. +# Include 'api' if there is a change to a library API. +# Default: '[user]' +change_logs: [] diff --git a/exporter/azuremonitorexporter/log_to_envelope.go b/exporter/azuremonitorexporter/log_to_envelope.go index 83af111ccb14..693fb8037cc7 100644 --- a/exporter/azuremonitorexporter/log_to_envelope.go +++ b/exporter/azuremonitorexporter/log_to_envelope.go @@ -30,7 +30,7 @@ func (packer *logPacker) LogRecordToEnvelope(logRecord plog.LogRecord, resource messageData.SeverityLevel = packer.toAiSeverityLevel(logRecord.SeverityNumber()) - messageData.Message = logRecord.Body().Str() + messageData.Message = logRecord.Body().AsString() envelope.Tags[contracts.OperationId] = traceutil.TraceIDToHexOrEmptyString(logRecord.TraceID()) envelope.Tags[contracts.OperationParentId] = traceutil.SpanIDToHexOrEmptyString(logRecord.SpanID()) diff --git a/exporter/azuremonitorexporter/logexporter_test.go b/exporter/azuremonitorexporter/logexporter_test.go index cdea52b7a36c..0e5566628aac 100644 --- a/exporter/azuremonitorexporter/logexporter_test.go +++ b/exporter/azuremonitorexporter/logexporter_test.go @@ -15,11 +15,10 @@ import ( "github.com/microsoft/ApplicationInsights-Go/appinsights/contracts" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "go.opentelemetry.io/collector/pdata/pcommon" "go.opentelemetry.io/collector/pdata/plog" conventions "go.opentelemetry.io/collector/semconv/v1.6.1" "go.uber.org/zap" - - "github.com/open-telemetry/opentelemetry-collector-contrib/internal/coreinternal/traceutil" ) const ( @@ -28,7 +27,9 @@ const ( ) var ( - testLogs = []byte(`{"resourceLogs":[{"resource":{"attributes":[{"key":"service.name","value":{"stringValue":"dotnet"}}]},"scopeLogs":[{"scope":{},"logRecords":[{"timeUnixNano":"1643240673066096200","severityText":"Information","body":{"stringValue":"Message Body"},"flags":1,"traceId":"7b20d1349ef9b6d6f9d4d1d4a3ac2e82","spanId":"0c2ad924e1771630"},{"timeUnixNano":"0","observedTimeUnixNano":"1643240673066096200","severityText":"Information","body":{"stringValue":"Message Body"},"flags":1,"traceId":"7b20d1349ef9b6d6f9d4d1d4a3ac2e82","spanId":"0c2ad924e1771630"},{"timeUnixNano":"0","observedTimeUnixNano":"0","severityText":"Information","body":{"stringValue":"Message Body"},"flags":1,"traceId":"7b20d1349ef9b6d6f9d4d1d4a3ac2e82","spanId":"0c2ad924e1771630"}]}]}]}`) + testLogTime = time.Date(2020, 2, 11, 20, 26, 13, 789, time.UTC) + testLogTimestamp = pcommon.NewTimestampFromTime(testLogTime) + testStringBody = "Message Body" severityLevelMap = map[plog.SeverityNumber]contracts.SeverityLevel{ plog.SeverityNumberTrace: contracts.Verbose, plog.SeverityNumberDebug4: contracts.Verbose, @@ -52,28 +53,32 @@ func TestLogRecordToEnvelope(t *testing.T) { } tests := []struct { - name string - logRecord plog.LogRecord + name string + index int }{ { - name: "timestamp is correct", - logRecord: getTestLogRecord(t, 0), + name: "timestamp is correct", + index: 0, + }, + { + name: "timestamp is empty", + index: 1, }, { - name: "timestamp is empty", - logRecord: getTestLogRecord(t, 1), + name: "timestamp is empty and observed timestamp is empty", + index: 2, }, { - name: "timestamp is empty and observed timestamp is empty", - logRecord: getTestLogRecord(t, 2), + name: "non-string body", + index: 3, }, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - logRecord := tt.logRecord + resource, scope, logRecord := getTestLogRecord(t, tt.index) logPacker := getLogPacker() - envelope := logPacker.LogRecordToEnvelope(logRecord, getResource(), getScope()) + envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) require.NotNil(t, envelope) assert.Equal(t, defaultEnvelopeName, envelope.Name) @@ -85,14 +90,10 @@ func TestLogRecordToEnvelope(t *testing.T) { require.NotNil(t, envelopeData.BaseData) messageData := envelopeData.BaseData.(*contracts.MessageData) - assert.Equal(t, messageData.Message, logRecord.Body().Str()) - assert.Equal(t, messageData.SeverityLevel, contracts.Information) - - hexTraceID := traceutil.TraceIDToHexOrEmptyString(logRecord.TraceID()) - assert.Equal(t, envelope.Tags[contracts.OperationId], hexTraceID) - - hexSpanID := traceutil.SpanIDToHexOrEmptyString(logRecord.SpanID()) - assert.Equal(t, envelope.Tags[contracts.OperationParentId], hexSpanID) + assert.Equal(t, logRecord.Body().AsString(), messageData.Message) + assert.Equal(t, contracts.Information, messageData.SeverityLevel) + assert.Equal(t, defaultTraceIDAsHex, envelope.Tags[contracts.OperationId]) + assert.Equal(t, defaultSpanIDAsHex, envelope.Tags[contracts.OperationParentId]) }) } } @@ -102,7 +103,7 @@ func TestToAiSeverityLevel(t *testing.T) { logPacker := getLogPacker() for sn, expectedSeverityLevel := range severityLevelMap { severityLevel := logPacker.toAiSeverityLevel(sn) - assert.Equal(t, severityLevel, expectedSeverityLevel) + assert.Equal(t, expectedSeverityLevel, severityLevel) } } @@ -115,18 +116,18 @@ func TestExporterLogDataCallback(t *testing.T) { assert.NoError(t, exporter.onLogData(context.Background(), logs)) - mockTransportChannel.AssertNumberOfCalls(t, "Send", 3) + mockTransportChannel.AssertNumberOfCalls(t, "Send", 4) } func TestLogDataAttributesMapping(t *testing.T) { logPacker := getLogPacker() - logRecord := getTestLogRecord(t, 2) + resource, scope, logRecord := getTestLogRecord(t, 2) logRecord.Attributes().PutInt("attribute_1", 10) logRecord.Attributes().PutStr("attribute_2", "value_2") logRecord.Attributes().PutBool("attribute_3", true) logRecord.Attributes().PutDouble("attribute_4", 1.2) - envelope := logPacker.LogRecordToEnvelope(logRecord, getResource(), getScope()) + envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) actualProperties := envelope.Data.(*contracts.Data).BaseData.(*contracts.MessageData).Properties assert.Contains(t, actualProperties["attribute_1"], "10") @@ -136,11 +137,10 @@ func TestLogDataAttributesMapping(t *testing.T) { } func TestLogRecordToEnvelopeResourceAttributes(t *testing.T) { - logRecord := getTestLogRecord(t, 1) + resource, scope, logRecord := getTestLogRecord(t, 1) logPacker := getLogPacker() - resource := getResource() - envelope := logPacker.LogRecordToEnvelope(logRecord, resource, getScope()) + envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) require.NotEmpty(t, resource.Attributes()) envelopeData := envelope.Data.(*contracts.Data).BaseData.(*contracts.MessageData) @@ -151,11 +151,10 @@ func TestLogRecordToEnvelopeInstrumentationScope(t *testing.T) { const aiInstrumentationLibraryNameConvention = "instrumentationlibrary.name" const aiInstrumentationLibraryVersionConvention = "instrumentationlibrary.version" - logRecord := getTestLogRecord(t, 1) + resource, scope, logRecord := getTestLogRecord(t, 1) logPacker := getLogPacker() - scope := getScope() - envelope := logPacker.LogRecordToEnvelope(logRecord, getResource(), scope) + envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) envelopeData := envelope.Data.(*contracts.Data).BaseData.(*contracts.MessageData) require.Equal(t, scope.Name(), envelopeData.Properties[aiInstrumentationLibraryNameConvention]) @@ -166,11 +165,10 @@ func TestLogRecordToEnvelopeCloudTags(t *testing.T) { const aiCloudRoleConvention = "ai.cloud.role" const aiCloudRoleInstanceConvention = "ai.cloud.roleInstance" - logRecord := getTestLogRecord(t, 1) + resource, scope, logRecord := getTestLogRecord(t, 1) logPacker := getLogPacker() - resource := getResource() - envelope := logPacker.LogRecordToEnvelope(logRecord, resource, getScope()) + envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) resourceAttributes := resource.Attributes().AsRaw() expectedCloudRole := resourceAttributes[conventions.AttributeServiceNamespace].(string) + "." + resourceAttributes[conventions.AttributeServiceName].(string) @@ -192,19 +190,72 @@ func getLogPacker() *logPacker { } func getTestLogs(tb testing.TB) plog.Logs { - logsMarshaler := &plog.JSONUnmarshaler{} - logs, err := logsMarshaler.UnmarshalLogs(testLogs) - assert.NoError(tb, err, "Can't unmarshal testing logs data -> %s", err) + logs := plog.NewLogs() + + // add the resource + resourceLogs := logs.ResourceLogs().AppendEmpty() + resource := resourceLogs.Resource() + resource.Attributes().PutStr(conventions.AttributeServiceName, defaultServiceName) + resource.Attributes().PutStr(conventions.AttributeServiceNamespace, defaultServiceNamespace) + resource.Attributes().PutStr(conventions.AttributeServiceInstanceID, defaultServiceInstance) + + // add the scope + scopeLogs := resourceLogs.ScopeLogs().AppendEmpty() + scope := scopeLogs.Scope() + scope.SetName(defaultScopeName) + scope.SetVersion(defaultScopeVersion) + + // add the log records + log := scopeLogs.LogRecords().AppendEmpty() + log.SetTimestamp(testLogTimestamp) + log.SetSeverityNumber(plog.SeverityNumberInfo) + log.SetSeverityText("Information") + log.SetFlags(1) + log.SetSpanID(defaultSpanID) + log.SetTraceID(defaultTraceID) + log.Body().SetStr(testStringBody) + + log = scopeLogs.LogRecords().AppendEmpty() + log.SetObservedTimestamp(testLogTimestamp) + log.SetSeverityNumber(plog.SeverityNumberInfo) + log.SetSeverityText("Information") + log.SetFlags(1) + log.SetSpanID(defaultSpanID) + log.SetTraceID(defaultTraceID) + log.Body().SetStr(testStringBody) + + log = scopeLogs.LogRecords().AppendEmpty() + log.SetSeverityNumber(plog.SeverityNumberInfo) + log.SetSeverityText("Information") + log.SetFlags(1) + log.SetSpanID(defaultSpanID) + log.SetTraceID(defaultTraceID) + log.Body().SetStr(testStringBody) + + log = scopeLogs.LogRecords().AppendEmpty() + log.SetTimestamp(testLogTimestamp) + log.SetSeverityNumber(plog.SeverityNumberInfo) + log.SetSeverityText("Information") + log.SetFlags(1) + log.SetSpanID(defaultSpanID) + log.SetTraceID(defaultTraceID) + + bodyMap := log.Body().SetEmptyMap() + bodyMap.PutStr("key1", "value1") + bodyMap.PutBool("key2", true) + return logs } -func getTestLogRecord(tb testing.TB, index int) plog.LogRecord { +func getTestLogRecord(tb testing.TB, index int) (pcommon.Resource, pcommon.InstrumentationScope, plog.LogRecord) { var logRecord plog.LogRecord logs := getTestLogs(tb) resourceLogs := logs.ResourceLogs() + resource := resourceLogs.At(0).Resource() scopeLogs := resourceLogs.At(0).ScopeLogs() + scope := scopeLogs.At(0).Scope() logRecords := scopeLogs.At(0).LogRecords() logRecord = logRecords.At(index) - return logRecord + return resource, scope, logRecord } From b7841158e9fac9227fe45943e49dd93ef604cad5 Mon Sep 17 00:00:00 2001 From: Peter Wiese Date: Fri, 4 Aug 2023 13:13:45 -0700 Subject: [PATCH 2/2] Fix linting error --- .../azuremonitorexporter/logexporter_test.go | 21 +++++++++---------- 1 file changed, 10 insertions(+), 11 deletions(-) diff --git a/exporter/azuremonitorexporter/logexporter_test.go b/exporter/azuremonitorexporter/logexporter_test.go index 0e5566628aac..fbf111631e1d 100644 --- a/exporter/azuremonitorexporter/logexporter_test.go +++ b/exporter/azuremonitorexporter/logexporter_test.go @@ -76,7 +76,7 @@ func TestLogRecordToEnvelope(t *testing.T) { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - resource, scope, logRecord := getTestLogRecord(t, tt.index) + resource, scope, logRecord := getTestLogRecord(tt.index) logPacker := getLogPacker() envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) @@ -112,7 +112,7 @@ func TestExporterLogDataCallback(t *testing.T) { mockTransportChannel := getMockTransportChannel() exporter := getLogsExporter(defaultConfig, mockTransportChannel) - logs := getTestLogs(t) + logs := getTestLogs() assert.NoError(t, exporter.onLogData(context.Background(), logs)) @@ -121,7 +121,7 @@ func TestExporterLogDataCallback(t *testing.T) { func TestLogDataAttributesMapping(t *testing.T) { logPacker := getLogPacker() - resource, scope, logRecord := getTestLogRecord(t, 2) + resource, scope, logRecord := getTestLogRecord(2) logRecord.Attributes().PutInt("attribute_1", 10) logRecord.Attributes().PutStr("attribute_2", "value_2") logRecord.Attributes().PutBool("attribute_3", true) @@ -137,7 +137,7 @@ func TestLogDataAttributesMapping(t *testing.T) { } func TestLogRecordToEnvelopeResourceAttributes(t *testing.T) { - resource, scope, logRecord := getTestLogRecord(t, 1) + resource, scope, logRecord := getTestLogRecord(1) logPacker := getLogPacker() envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) @@ -151,7 +151,7 @@ func TestLogRecordToEnvelopeInstrumentationScope(t *testing.T) { const aiInstrumentationLibraryNameConvention = "instrumentationlibrary.name" const aiInstrumentationLibraryVersionConvention = "instrumentationlibrary.version" - resource, scope, logRecord := getTestLogRecord(t, 1) + resource, scope, logRecord := getTestLogRecord(1) logPacker := getLogPacker() envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) @@ -165,7 +165,7 @@ func TestLogRecordToEnvelopeCloudTags(t *testing.T) { const aiCloudRoleConvention = "ai.cloud.role" const aiCloudRoleInstanceConvention = "ai.cloud.roleInstance" - resource, scope, logRecord := getTestLogRecord(t, 1) + resource, scope, logRecord := getTestLogRecord(1) logPacker := getLogPacker() envelope := logPacker.LogRecordToEnvelope(logRecord, resource, scope) @@ -189,7 +189,7 @@ func getLogPacker() *logPacker { return newLogPacker(zap.NewNop()) } -func getTestLogs(tb testing.TB) plog.Logs { +func getTestLogs() plog.Logs { logs := plog.NewLogs() // add the resource @@ -247,15 +247,14 @@ func getTestLogs(tb testing.TB) plog.Logs { return logs } -func getTestLogRecord(tb testing.TB, index int) (pcommon.Resource, pcommon.InstrumentationScope, plog.LogRecord) { - var logRecord plog.LogRecord - logs := getTestLogs(tb) +func getTestLogRecord(index int) (pcommon.Resource, pcommon.InstrumentationScope, plog.LogRecord) { + logs := getTestLogs() resourceLogs := logs.ResourceLogs() resource := resourceLogs.At(0).Resource() scopeLogs := resourceLogs.At(0).ScopeLogs() scope := scopeLogs.At(0).Scope() logRecords := scopeLogs.At(0).LogRecords() - logRecord = logRecords.At(index) + logRecord := logRecords.At(index) return resource, scope, logRecord }