Skip to content

Commit

Permalink
Fixes for Log Scope Processing (#39453)
Browse files Browse the repository at this point in the history 
* Fixes for Log Scope Processing

* Update changelog

* PR Feedback.

* Add level

* PR feedback.

* ChangeLog update
  • Loading branch information
@rajkumar-rangaraj
rajkumar-rangaraj authored Oct 31, 2023
1 parent 8d7f7de commit 96b537f
Show file tree
Hide file tree
Showing 4 changed files with 282 additions and 64 deletions.
25 changes: 21 additions & 4 deletions sdk/monitor/Azure.Monitor.OpenTelemetry.Exporter/CHANGELOG.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,13 +15,30 @@
### Bugs Fixed

* Fixed an issue during network failures which prevented the exporter to store
the telemetry offline for retrying at a later time.
([#38832](https://github.com/Azure/azure-sdk-for-net/pull/38832))
the telemetry offline for retrying at a later time.
([#38832](https://github.com/Azure/azure-sdk-for-net/pull/38832))

* Fixed an issue where `OriginalFormat` persisted in TraceTelemetry properties
with IncludeFormattedMessage enabled in OpenTelemetry LoggerProvider. This fix
prevents data duplication in message fields and properties.
with IncludeFormattedMessage set to true on [
OpenTelemetryLoggerOptions](https://github.com/open-telemetry/opentelemetry-dotnet/blob/main/src/OpenTelemetry/Logs/ILogger/OpenTelemetryLoggerOptions.cs)
of the OpenTelemetry LoggerProvider. This fix prevents data duplication in
message fields and properties.
([#39308](https://github.com/Azure/azure-sdk-for-net/pull/39308))

* Fixed an issue related to the processing of scopes that do not conform to a
key-value pair structure.
([#39453](https://github.com/Azure/azure-sdk-for-net/pull/39453))
* **Previous Behavior**: Logging a scope with a statement like
`logger.BeginScope("SomeScopeValue")` would result in adding
'SomeScopeValue' to the properties using a key that follows the pattern
'scope->*'. Additionally, 'OriginalFormatScope_*' keys were used to handle
formatted strings within the scope.
* **New Behavior**:
* Non-key-value pair scopes are no longer added to the properties,
resulting in cleaner and more efficient log output.
* 'OriginalFormatScope_*' keys have been removed.
* In case of duplicate keys within the scopes, only the first entry is
retained, while all subsequent duplicate entries are discarded.

### Other Changes

Expand Down
24 changes: 24 additions & 0 deletions ...nitor.OpenTelemetry.Exporter/src/Internals/Diagnostics/AzureMonitorExporterEventSource.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -395,5 +395,29 @@ public void PartialContentResponseUnhandled(TelemetryErrorDetails error)

[Event(39, Message = "Received a partial success from ingestion. This status code is not handled and telemetry will be lost. Error StatusCode: {0}. Error Message: {1}", Level = EventLevel.Warning)]
public void PartialContentResponseUnhandled(string errorStatusCode, string errorMessage) => WriteEvent(39, errorStatusCode, errorMessage);

[NonEvent]
public void FailedToAddScopeItem(string key, Exception ex)
{
if (IsEnabled(EventLevel.Warning))
{
FailedToAddScopeItem(key, ex.FlattenException().ToInvariantString());
}
}

[Event(40, Message = "An exception {1} occurred while adding the scope value associated with the key {0}", Level = EventLevel.Warning)]
public void FailedToAddScopeItem(string key, string exceptionMessage) => WriteEvent(40, key, exceptionMessage);

[NonEvent]
public void FailedToAddLogAttribute(string key, Exception ex)
{
if (IsEnabled(EventLevel.Warning))
{
FailedToAddLogAttribute(key, ex.FlattenException().ToInvariantString());
}
}

[Event(41, Message = "An exception {1} occurred while adding the log attribute associated with the key {0}", Level = EventLevel.Warning)]
public void FailedToAddLogAttribute(string key, string exceptionMessage) => WriteEvent(41, key, exceptionMessage);
}
}
105 changes: 46 additions & 59 deletions sdk/monitor/Azure.Monitor.OpenTelemetry.Exporter/src/Internals/LogsHelper.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,13 +2,11 @@
// Licensed under the MIT License.

using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Diagnostics;
using System.Globalization;
using System.Linq;
using System.Reflection;
using System.Text;
using Azure.Monitor.OpenTelemetry.Exporter.Internals.Diagnostics;
using Azure.Monitor.OpenTelemetry.Exporter.Models;

Expand All @@ -22,8 +20,32 @@ namespace Azure.Monitor.OpenTelemetry.Exporter.Internals
internal static class LogsHelper
{
private const int Version = 2;
private static readonly ConcurrentDictionary<int, string> s_depthCache = new ConcurrentDictionary<int, string>();
private static readonly Func<int, string> s_convertDepthToStringRef = ConvertDepthToString;
private static readonly Action<LogRecordScope, IDictionary<string, string>> s_processScope = (scope, properties) =>
{
foreach (KeyValuePair<string, object?> scopeItem in scope)
{
if (string.IsNullOrEmpty(scopeItem.Key) || scopeItem.Key == "{OriginalFormat}")
{
continue;
}

// Note: if Key exceeds MaxLength, the entire KVP will be dropped.
if (scopeItem.Key.Length <= SchemaConstants.MessageData_Properties_MaxKeyLength && scopeItem.Value != null)
{
try
{
if (!properties.ContainsKey(scopeItem.Key))
{
properties.Add(scopeItem.Key, Convert.ToString(scopeItem.Value, CultureInfo.InvariantCulture)?.Truncate(SchemaConstants.MessageData_Properties_MaxValueLength)!);
}
}
catch (Exception ex)
{
AzureMonitorExporterEventSource.Log.FailedToAddScopeItem(scopeItem.Key, ex);
}
}
}
};

internal static List<TelemetryItem> OtelToAzureMonitorLogs(Batch<LogRecord> batchLogRecord, AzureMonitorResource? resource, string instrumentationKey)
{
Expand Down Expand Up @@ -69,28 +91,38 @@ internal static List<TelemetryItem> OtelToAzureMonitorLogs(Batch<LogRecord> batc

foreach (KeyValuePair<string, object?> item in logRecord.Attributes ?? Enumerable.Empty<KeyValuePair<string, object?>>())
{
if (item.Key.Length <= SchemaConstants.KVP_MaxKeyLength && item.Value != null)
// Note: if Key exceeds MaxLength, the entire KVP will be dropped.
if (item.Key.Length <= SchemaConstants.MessageData_Properties_MaxKeyLength && item.Value != null)
{
// Note: if Key exceeds MaxLength, the entire KVP will be dropped.
if (item.Key == "{OriginalFormat}")
try
{
if (logRecord.Exception?.Message != null)
if (item.Key == "{OriginalFormat}")
{
properties.Add("OriginalFormat", item.Value.ToString().Truncate(SchemaConstants.KVP_MaxValueLength) ?? "null");
if (logRecord.Exception?.Message != null)
{
properties.Add("OriginalFormat", item.Value.ToString().Truncate(SchemaConstants.MessageData_Properties_MaxValueLength)!);
}
else if (message == null)
{
message = item.Value.ToString();
}
}
else if (message == null)
else
{
message = item.Value.ToString();
if (!properties.ContainsKey(item.Key))
{
properties.Add(item.Key, item.Value.ToString().Truncate(SchemaConstants.MessageData_Properties_MaxValueLength)!);
}
}
}
else
catch (Exception ex)
{
properties.Add(item.Key, item.Value.ToString().Truncate(SchemaConstants.KVP_MaxValueLength) ?? "null");
AzureMonitorExporterEventSource.Log.FailedToAddLogAttribute(item.Key, ex);
}
}
}

WriteScopeInformation(logRecord, properties);
logRecord.ForEachScope(s_processScope, properties);

if (logRecord.EventId.Id != 0)
{
Expand All @@ -105,49 +137,6 @@ internal static List<TelemetryItem> OtelToAzureMonitorLogs(Batch<LogRecord> batc
return message;
}

internal static void WriteScopeInformation(LogRecord logRecord, IDictionary<string, string> properties)
{
StringBuilder? builder = null;
int originalScopeDepth = 1;
logRecord.ForEachScope(ProcessScope, properties);

void ProcessScope(LogRecordScope scope, IDictionary<string, string> properties)
{
int valueDepth = 1;
foreach (KeyValuePair<string, object?> scopeItem in scope)
{
if (string.IsNullOrEmpty(scopeItem.Key))
{
builder ??= new StringBuilder();
builder.Append(" => ").Append(scope.Scope);
}
else if (scopeItem.Key == "{OriginalFormat}")
{
properties.Add($"OriginalFormatScope_{s_depthCache.GetOrAdd(originalScopeDepth, s_convertDepthToStringRef)}",
Convert.ToString(scope.Scope, CultureInfo.InvariantCulture) ?? "null");
}
else if (!properties.TryGetValue(scopeItem.Key, out _))
{
properties.Add(scopeItem.Key,
Convert.ToString(scopeItem.Value, CultureInfo.InvariantCulture) ?? "null");
}
else
{
properties.Add($"{scopeItem.Key}_{s_depthCache.GetOrAdd(originalScopeDepth, s_convertDepthToStringRef)}_{s_depthCache.GetOrAdd(valueDepth, s_convertDepthToStringRef)}",
Convert.ToString(scopeItem.Value, CultureInfo.InvariantCulture) ?? "null");
valueDepth++;
}
}

originalScopeDepth++;
}

if (builder?.Length > 0)
{
properties.Add("Scope", builder.ToString().Truncate(SchemaConstants.KVP_MaxValueLength));
}
}

internal static string GetProblemId(Exception exception)
{
string methodName = "UnknownMethod";
Expand Down Expand Up @@ -210,7 +199,5 @@ internal static SeverityLevel GetSeverityLevel(LogLevel logLevel)
return SeverityLevel.Verbose;
}
}

private static string ConvertDepthToString(int depth) => $"{depth}";
}
}
Loading

0 comments on commit 96b537f

Please sign in to comment.