From 426e660499d7bd331f66bb3336daf1932b8a8e4a Mon Sep 17 00:00:00 2001 From: Andrzej Stencel Date: Fri, 21 Jun 2024 09:32:05 +0200 Subject: [PATCH] [exporter/debug] format log records as one-liners in `normal` verbosity (#10225) #### Description Changes the behavior of `normal` verbosity of the Debug exporter for logs to display each log record in one line of text. Note that if the body of the log record contains newlines, the output will be displayed in multiple lines. This pull request is part of https://github.com/open-telemetry/opentelemetry-collector/issues/7806; it implements the change for logs. The changes for metrics and [traces](https://github.com/open-telemetry/opentelemetry-collector/pull/10280) will be proposed in separate pull requests. The implementation in this pull request does not display any details on the resource or the scope of the logs. I would like to propose displaying the resource and the scope as separate lines in a separate pull request. This change applies to the Debug exporter only. The behavior of the Logging exporter remains unchanged. To use this behavior, switch from the deprecated Logging exporter to Debug exporter. #### Link to tracking issue - https://github.com/open-telemetry/opentelemetry-collector/issues/7806 #### Testing Added unit tests for the formatter. #### Documentation Described the formatting in the Debug exporter's README. --------- Co-authored-by: Roger Coll Co-authored-by: Pablo Baeyens --- .../debug-exporter-normal-verbosity-logs.yaml | 25 ++++ exporter/debugexporter/README.md | 18 ++- exporter/debugexporter/exporter.go | 12 +- .../debugexporter/internal/normal/logs.go | 52 ++++++++ .../internal/normal/logs_test.go | 118 ++++++++++++++++++ 5 files changed, 221 insertions(+), 4 deletions(-) create mode 100644 .chloggen/debug-exporter-normal-verbosity-logs.yaml create mode 100644 exporter/debugexporter/internal/normal/logs.go create mode 100644 exporter/debugexporter/internal/normal/logs_test.go diff --git a/.chloggen/debug-exporter-normal-verbosity-logs.yaml b/.chloggen/debug-exporter-normal-verbosity-logs.yaml new file mode 100644 index 00000000000..d874275a547 --- /dev/null +++ b/.chloggen/debug-exporter-normal-verbosity-logs.yaml @@ -0,0 +1,25 @@ +# Use this changelog template to create an entry for release notes. + +# One of 'breaking', 'deprecation', 'new_component', 'enhancement', 'bug_fix' +change_type: enhancement + +# The name of the component, or a single word describing the area of concern, (e.g. otlpreceiver) +component: exporter/debug + +# A brief description of the change. Surround your text with quotes ("") if it needs to start with a backtick (`). +note: In `normal` verbosity, display one line of text for each log record + +# One or more tracking issues or pull requests related to the change +issues: [7806] + +# (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: + +# 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/debugexporter/README.md b/exporter/debugexporter/README.md index 344c55c3515..6f8eac92623 100644 --- a/exporter/debugexporter/README.md +++ b/exporter/debugexporter/README.md @@ -62,8 +62,22 @@ Here's an example output: ### Normal verbosity -With `verbosity: normal`, the exporter's behavior is currently the same as with `verbosity: basic`. -See above for more details. +With `verbosity: normal`, the exporter outputs about one line for each telemetry record, including its body and attributes. +The "one line per telemetry record" is not a strict rule. +For example, logs with multiline body will be output as multiple lines. + +> [!IMPORTANT] +> Currently the `normal` verbosity is only implemented for logs. +> Metrics and traces are going to be implemented in the future. +> The current behavior for metrics and traces is the same as in `basic` verbosity. + +Here's an example output: + +```console +2024-05-27T12:46:22.423+0200 info LogsExporter {"kind": "exporter", "data_type": "logs", "name": "debug", "resource logs": 1, "log records": 1} +2024-05-27T12:46:22.423+0200 info the message app=server + {"kind": "exporter", "data_type": "logs", "name": "debug"} +``` ### Detailed verbosity diff --git a/exporter/debugexporter/exporter.go b/exporter/debugexporter/exporter.go index 191ac562563..ab5865e41c7 100644 --- a/exporter/debugexporter/exporter.go +++ b/exporter/debugexporter/exporter.go @@ -13,6 +13,7 @@ import ( "go.uber.org/zap" "go.opentelemetry.io/collector/config/configtelemetry" + "go.opentelemetry.io/collector/exporter/debugexporter/internal/normal" "go.opentelemetry.io/collector/exporter/internal/otlptext" "go.opentelemetry.io/collector/pdata/plog" "go.opentelemetry.io/collector/pdata/pmetric" @@ -28,10 +29,16 @@ type debugExporter struct { } func newDebugExporter(logger *zap.Logger, verbosity configtelemetry.Level) *debugExporter { + var logsMarshaler plog.Marshaler + if verbosity == configtelemetry.LevelDetailed { + logsMarshaler = otlptext.NewTextLogsMarshaler() + } else { + logsMarshaler = normal.NewNormalLogsMarshaler() + } return &debugExporter{ verbosity: verbosity, logger: logger, - logsMarshaler: otlptext.NewTextLogsMarshaler(), + logsMarshaler: logsMarshaler, metricsMarshaler: otlptext.NewTextMetricsMarshaler(), tracesMarshaler: otlptext.NewTextTracesMarshaler(), } @@ -74,7 +81,8 @@ func (s *debugExporter) pushLogs(_ context.Context, ld plog.Logs) error { s.logger.Info("LogsExporter", zap.Int("resource logs", ld.ResourceLogs().Len()), zap.Int("log records", ld.LogRecordCount())) - if s.verbosity != configtelemetry.LevelDetailed { + + if s.verbosity == configtelemetry.LevelBasic { return nil } diff --git a/exporter/debugexporter/internal/normal/logs.go b/exporter/debugexporter/internal/normal/logs.go new file mode 100644 index 00000000000..9a2ff4cd808 --- /dev/null +++ b/exporter/debugexporter/internal/normal/logs.go @@ -0,0 +1,52 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package normal // import "go.opentelemetry.io/collector/exporter/debugexporter/internal/normal" + +import ( + "bytes" + "fmt" + "strings" + + "go.opentelemetry.io/collector/pdata/pcommon" + "go.opentelemetry.io/collector/pdata/plog" +) + +type normalLogsMarshaler struct{} + +// Ensure normalLogsMarshaller implements interface plog.Marshaler +var _ plog.Marshaler = normalLogsMarshaler{} + +// NewNormalLogsMarshaler returns a plog.Marshaler for normal verbosity. It writes one line of text per log record +func NewNormalLogsMarshaler() plog.Marshaler { + return normalLogsMarshaler{} +} + +func (normalLogsMarshaler) MarshalLogs(ld plog.Logs) ([]byte, error) { + var buffer bytes.Buffer + for i := 0; i < ld.ResourceLogs().Len(); i++ { + resourceLog := ld.ResourceLogs().At(i) + for j := 0; j < resourceLog.ScopeLogs().Len(); j++ { + scopeLog := resourceLog.ScopeLogs().At(j) + for k := 0; k < scopeLog.LogRecords().Len(); k++ { + logRecord := scopeLog.LogRecords().At(k) + logAttributes := writeAttributes(logRecord.Attributes()) + + logString := fmt.Sprintf("%s %s", logRecord.Body().AsString(), strings.Join(logAttributes, " ")) + buffer.WriteString(logString) + buffer.WriteString("\n") + } + } + } + return buffer.Bytes(), nil +} + +// writeAttributes returns a slice of strings in the form "attrKey=attrValue" +func writeAttributes(attributes pcommon.Map) (attributeStrings []string) { + attributes.Range(func(k string, v pcommon.Value) bool { + attribute := fmt.Sprintf("%s=%s", k, v.AsString()) + attributeStrings = append(attributeStrings, attribute) + return true + }) + return attributeStrings +} diff --git a/exporter/debugexporter/internal/normal/logs_test.go b/exporter/debugexporter/internal/normal/logs_test.go new file mode 100644 index 00000000000..8aafa49862a --- /dev/null +++ b/exporter/debugexporter/internal/normal/logs_test.go @@ -0,0 +1,118 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package normal + +import ( + "testing" + "time" + + "github.com/stretchr/testify/assert" + + "go.opentelemetry.io/collector/pdata/pcommon" + "go.opentelemetry.io/collector/pdata/plog" +) + +func TestMarshalLogs(t *testing.T) { + tests := []struct { + name string + input plog.Logs + expected string + }{ + { + name: "empty logs", + input: plog.NewLogs(), + expected: "", + }, + { + name: "one log record", + input: func() plog.Logs { + logs := plog.NewLogs() + logRecord := logs.ResourceLogs().AppendEmpty().ScopeLogs().AppendEmpty().LogRecords().AppendEmpty() + logRecord.SetTimestamp(pcommon.NewTimestampFromTime(time.Date(2024, 1, 23, 17, 54, 41, 153, time.UTC))) + logRecord.SetSeverityNumber(plog.SeverityNumberInfo) + logRecord.SetSeverityText("INFO") + logRecord.Body().SetStr("Single line log message") + logRecord.Attributes().PutStr("key1", "value1") + logRecord.Attributes().PutStr("key2", "value2") + return logs + }(), + expected: `Single line log message key1=value1 key2=value2 +`, + }, + { + name: "multiline log", + input: func() plog.Logs { + logs := plog.NewLogs() + logRecord := logs.ResourceLogs().AppendEmpty().ScopeLogs().AppendEmpty().LogRecords().AppendEmpty() + logRecord.SetTimestamp(pcommon.NewTimestampFromTime(time.Date(2024, 1, 23, 17, 54, 41, 153, time.UTC))) + logRecord.SetSeverityNumber(plog.SeverityNumberInfo) + logRecord.SetSeverityText("INFO") + logRecord.Body().SetStr("First line of the log message\n second line of the log message") + logRecord.Attributes().PutStr("key1", "value1") + logRecord.Attributes().PutStr("key2", "value2") + return logs + }(), + expected: `First line of the log message + second line of the log message key1=value1 key2=value2 +`, + }, + { + name: "two log records", + input: func() plog.Logs { + logs := plog.NewLogs() + logRecords := logs.ResourceLogs().AppendEmpty().ScopeLogs().AppendEmpty().LogRecords() + + logRecord := logRecords.AppendEmpty() + logRecord.SetTimestamp(pcommon.NewTimestampFromTime(time.Date(2024, 1, 23, 17, 54, 41, 153, time.UTC))) + logRecord.SetSeverityNumber(plog.SeverityNumberInfo) + logRecord.SetSeverityText("INFO") + logRecord.Body().SetStr("Single line log message") + logRecord.Attributes().PutStr("key1", "value1") + logRecord.Attributes().PutStr("key2", "value2") + + logRecord = logRecords.AppendEmpty() + logRecord.Body().SetStr("Multi-line\nlog message") + logRecord.Attributes().PutStr("mykey2", "myvalue2") + logRecord.Attributes().PutStr("mykey1", "myvalue1") + return logs + }(), + expected: `Single line log message key1=value1 key2=value2 +Multi-line +log message mykey2=myvalue2 mykey1=myvalue1 +`, + }, + { + name: "log with maps in body and attributes", + input: func() plog.Logs { + logs := plog.NewLogs() + logRecord := logs.ResourceLogs().AppendEmpty().ScopeLogs().AppendEmpty().LogRecords().AppendEmpty() + logRecord.SetTimestamp(pcommon.NewTimestampFromTime(time.Date(2020, 2, 11, 20, 26, 13, 789, time.UTC))) + logRecord.SetSeverityNumber(plog.SeverityNumberInfo) + logRecord.SetSeverityText("INFO") + body := logRecord.Body().SetEmptyMap() + body.PutStr("app", "CurrencyConverter") + bodyEvent := body.PutEmptyMap("event") + bodyEvent.PutStr("operation", "convert") + bodyEvent.PutStr("result", "success") + conversionAttr := logRecord.Attributes().PutEmptyMap("conversion") + conversionSourceAttr := conversionAttr.PutEmptyMap("source") + conversionSourceAttr.PutStr("currency", "USD") + conversionSourceAttr.PutDouble("amount", 34.22) + conversionDestinationAttr := conversionAttr.PutEmptyMap("destination") + conversionDestinationAttr.PutStr("currency", "EUR") + logRecord.Attributes().PutStr("service", "payments") + return logs + }(), + expected: `{"app":"CurrencyConverter","event":{"operation":"convert","result":"success"}} conversion={"destination":{"currency":"EUR"},"source":{"amount":34.22,"currency":"USD"}} service=payments +`, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + output, err := NewNormalLogsMarshaler().MarshalLogs(tt.input) + assert.NoError(t, err) + assert.Equal(t, tt.expected, string(output)) + }) + } +}