opentelemetry-dotnet
opentelemetry-dotnet copied to clipboard
Invalid Characters in "{OriginalFormat}" when using OTLPExporter
Package
OpenTelemetry.Exporter.OpenTelemetryProtocol
Package Version
| Package Name | Version |
|---|---|
| OpenTelemetry.Api | 1.9.0 |
| OpenTelemetry | 1.9.0 |
| TBD | TBD |
Runtime Version
net8.0
Description
We have encountered with the IncludeFormattedMessage setting in our OpenTelemetry .NET setup. When this setting is configured as false, the {OriginalFormat} field is not emitted, but the body remains unresolved. Conversely, when the setting is true, the {OriginalFormat} field is emitted, and the body is resolved. Unfortunately, our backend treats the {} characters as invalid, causing processing issues.
Here are sample log records for reference:
When IncludeFormattedMessage is set to false:
{ "body": "Food {name} price changed to {price}", "traceid": "trace-id-1", "spanid": "span-id-1", "severity": "Information", "attributes": { "name": "artichoke", "price": "9.99", "logrecord.event.id": 123456789, "logrecord.event.name": "PriceChange", "value": [ "[EventId, event-id-1]", "[EventType, event-type-1]", "[SourceNode, source-node-1]", "[SourceName, Internal]", "[Time, 08/06/2024 16:23:21]", "[ReceiveTime, 08/06/2024 16:23:21]", "[LocalTime, (null)]", "[Message, Price Changed]", "[Severity, 500]" ] }, "resources": { "service.instance.id": "instance-id-1", "service.name": "service-name-1", "service.namespace": "service-namespace-1", "service.version": "service-version-1", "telemetry.sdk.language": "dotnet", "telemetry.sdk.name": "opentelemetry", "telemetry.sdk.version": "1.9.0" }, "instrumentation_scope": { "name": "instrumentation-scope-name-1" } } When IncludeFormattedMessage is set to true:
{ "body": "Food artichoke price changed to 9.99", "traceid": "trace-id-2", "spanid": "span-id-2", "severity": "Information", "flags": 1, "attributes": { "name": "artichoke", "price": "9.99", "logrecord.event.id": 987654321, "logrecord.event.name": "PriceChange", "{OriginalFormat}": "Food {name} price changed to {price}" }, "resources": { "service.instance.id": "instance-id-2", "service.name": "service-name-2", "service.namespace": "service-namespace-2", "service.version": "service-version-2", "telemetry.sdk.language": "dotnet", "telemetry.sdk.name": "opentelemetry", "telemetry.sdk.version": "1.9.0" }, "instrumentation_scope": { "name": "instrumentation-scope-name-2" } }
Please help with a fix that allows us to resolve the body without emitting the {OriginalFormat} field. Alternatively, consider changing {OriginalFormat} to OriginalFormat in the OTLP stack similar to how its handled in the ConsoleLogRecordExporter
Steps to Reproduce
var loggerFactory = LoggerFactory.Create(builder => { builder.AddOpenTelemetry(logging => { logging.IncludeScopes = true; logging.IncludeFormattedMessage = true; logging.SetResourceBuilder(ResourceBuilder.CreateDefault().AddService( serviceName: "MyService", serviceVersion: "1.0.0")); logging.AddConsoleExporter(); }); });
Expected Result
{ "body": "Food artichoke price changed to 9.99", "traceid": "trace-id-2", "spanid": "span-id-2", "severity": "Information", "flags": 1, "attributes": { "name": "artichoke", "price": "9.99", "logrecord.event.id": 987654321, "logrecord.event.name": "PriceChange", "OriginalFormat": "Food {name} price changed to {price}" }, "resources": { "service.instance.id": "instance-id-2", "service.name": "service-name-2", "service.namespace": "service-namespace-2", "service.version": "service-version-2", "telemetry.sdk.language": "dotnet", "telemetry.sdk.name": "opentelemetry", "telemetry.sdk.version": "1.9.0" }, "instrumentation_scope": { "name": "instrumentation-scope-name-2" } }
Actual Result
{ "body": "Food artichoke price changed to 9.99", "traceid": "trace-id-2", "spanid": "span-id-2", "severity": "Information", "flags": 1, "attributes": { "name": "artichoke", "price": "9.99", "logrecord.event.id": 987654321, "logrecord.event.name": "PriceChange", "{OriginalFormat}": "Food {name} price changed to {price}" }, "resources": { "service.instance.id": "instance-id-2", "service.name": "service-name-2", "service.namespace": "service-namespace-2", "service.version": "service-version-2", "telemetry.sdk.language": "dotnet", "telemetry.sdk.name": "opentelemetry", "telemetry.sdk.version": "1.9.0" }, "instrumentation_scope": { "name": "instrumentation-scope-name-2" } }
Additional Context
No response
For better or worse, this is working as designed 🤣 We couldn't change it now without likely breaking users. We could introduce some settings/options to opt-into different behavior though.
I chatted offline with the user(s) and recommended to them as a workaround they investigate a custom processor to remove the {OriginalFormat} attribute and then add it back in with a different key.
More details...
The OtlpLogExporter will always emit a body:
-
When
IncludeFormattedMessage == truebody will be the formatted message and{OriginalFormat}is dropped (if found). Personally I don't think this is a great design. Perhaps it would have been better to always set body to the template (if we have one) and then put the formatted message into some other attribute. The spec has this log.record.original (experimental) maybe that would work. -
When
IncludeFormattedMessage == falsebody will be{OriginalFormat}if it was found otherwise it will be either the result of the formatter (if a formatter was provided) elseToStringof theTSTatepassed toILogger.Log.
We recommend keeping IncludeFormattedMessage false because formatting the string is expensive to do in the process and backends can do it lazily on demand from the message template if users really want to see it.
As far as adding options to change the behavior I think we should keep this open to gauge the demand and go from there.