Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Exporter.Geneva] Avoid allocation for serializing scopes #818

Merged
merged 12 commits into from
Dec 19, 2022
Merged

[Exporter.Geneva] Avoid allocation for serializing scopes #818

Show file tree
Hide file tree
Changes from 8 commits
Commits
Show all changes
12 commits
Select commit Hold shift + click to select a range
eab64bb
Update unit tests for scopes
utpilla Dec 11, 2022
9361c44
Update GenevaLogExporter
utpilla Dec 12, 2022
9f9b9ab
Merge remote-tracking branch 'origin/main' into utpilla/Update-Geneva…
utpilla Dec 12, 2022
481655b
Update CHANGELOG
utpilla Dec 12, 2022
85135db
Fix comment
utpilla Dec 12, 2022
526dad8
Merge with origin/main
utpilla Dec 15, 2022
bf16b05
Set hasEnvProperties for scope state
utpilla Dec 15, 2022
76a0c7e
Address PR comments
utpilla Dec 15, 2022
70be6d4
Merge branch 'main' into utpilla/Update-GenevaLogExporter
CodeBlanch Dec 15, 2022
e6b1807
Merge with origin/main
utpilla Dec 19, 2022
812e525
Merge branch 'utpilla/Update-GenevaLogExporter' of https://github.com…
utpilla Dec 19, 2022
cf0c5bd
Update Dispose method
utpilla Dec 19, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions src/OpenTelemetry.Exporter.Geneva/CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,9 @@
* Update OpenTelemetry to 1.4.0-rc.1
([#820](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/820))

* Avoid allocation when serializing scopes.
([#818](https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/818))

## 1.4.0-beta.6

Released 2022-Dec-09
Expand Down
130 changes: 90 additions & 40 deletions src/OpenTelemetry.Exporter.Geneva/MsgPackExporter/MsgPackLogExporter.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,10 +34,13 @@ internal sealed class MsgPackLogExporter : MsgPackExporter, IDisposable

private readonly ExceptionStackExportMode m_exportExceptionStack;

// This is used for Scopes
private readonly ThreadLocal<SerializationDataForScopes> m_serializationData = new(() => null);

private readonly string m_defaultEventName = "Log";
private readonly IReadOnlyDictionary<string, object> m_prepopulatedFields;
private readonly List<string> m_prepopulatedFieldKeys;
private static readonly ThreadLocal<byte[]> m_buffer = new ThreadLocal<byte[]>(() => null);
private static readonly ThreadLocal<byte[]> m_buffer = new(() => null);
private readonly byte[] m_bufferEpilogue;
private static readonly string[] logLevels = new string[7]
{
Expand Down Expand Up @@ -349,33 +352,29 @@ internal int SerializeLogRecord(LogRecord logRecord)
cntFields += 1;
}

logRecord.ForEachScope(ProcessScopeForIndividualColumns, (object)null);
void ProcessScopeForIndividualColumns(LogRecordScope scope, object state)
// Prepare state for scopes
var dataForScopes = this.m_serializationData.Value;
if (dataForScopes == null)
{
foreach (KeyValuePair<string, object> scopeItem in scope)
dataForScopes = new SerializationDataForScopes
{
if (string.IsNullOrEmpty(scopeItem.Key) || scopeItem.Key == "{OriginalFormat}")
{
continue;
}
Buffer = buffer,
};

if (this.m_customFields == null || this.m_customFields.ContainsKey(scopeItem.Key))
{
if (scopeItem.Value != null)
{
// null is not supported.
cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, scopeItem.Key);
cursor = MessagePackSerializer.Serialize(buffer, cursor, scopeItem.Value);
cntFields += 1;
}
}
else
{
hasEnvProperties = true;
}
}
this.m_serializationData.Value = dataForScopes;
}

dataForScopes.Cursor = cursor;
dataForScopes.FieldsCount = cntFields;
dataForScopes.HasEnvProperties = hasEnvProperties;

logRecord.ForEachScope(ProcessScopeForIndividualColumns, this);

// Update the variables that could have been modified in ProcessScopeForIndividualColumns
hasEnvProperties = dataForScopes.HasEnvProperties;
cursor = dataForScopes.Cursor;
cntFields = dataForScopes.FieldsCount;

if (hasEnvProperties)
{
// Iteration #2 - Get all "other" fields and collapse them into single field
Expand All @@ -399,24 +398,15 @@ void ProcessScopeForIndividualColumns(LogRecordScope scope, object state)
}
}

logRecord.ForEachScope(ProcessScopeForEnvProperties, (object)null);
void ProcessScopeForEnvProperties(LogRecordScope scope, object state)
{
foreach (KeyValuePair<string, object> scopeItem in scope)
{
if (string.IsNullOrEmpty(scopeItem.Key) || scopeItem.Key == "{OriginalFormat}")
{
continue;
}
// Prepare state for scopes
dataForScopes.Cursor = cursor;
dataForScopes.EnvPropertiesCount = envPropertiesCount;
utpilla marked this conversation as resolved.
Show resolved Hide resolved

if (!this.m_customFields.ContainsKey(scopeItem.Key))
{
cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, scopeItem.Key);
cursor = MessagePackSerializer.Serialize(buffer, cursor, scopeItem.Value);
envPropertiesCount += 1;
}
}
}
logRecord.ForEachScope(ProcessScopeForEnvProperties, this);

// Update the variables that could have been modified in ProcessScopeForEnvProperties
cursor = dataForScopes.Cursor;
envPropertiesCount = dataForScopes.EnvPropertiesCount;

cntFields += 1;
MessagePackSerializer.WriteUInt16(buffer, idxMapSizeEnvPropertiesPatch, envPropertiesCount);
Expand Down Expand Up @@ -583,4 +573,64 @@ public void Dispose()

this.isDisposed = true;
}

private static readonly Action<LogRecordScope, MsgPackLogExporter> ProcessScopeForIndividualColumns = (scope, state) =>
{
var stateData = state.m_serializationData.Value;
var customFields = state.m_customFields;

foreach (KeyValuePair<string, object> scopeItem in scope)
{
if (string.IsNullOrEmpty(scopeItem.Key) || scopeItem.Key == "{OriginalFormat}")
{
continue;
}

if (customFields == null || customFields.ContainsKey(scopeItem.Key))
{
if (scopeItem.Value != null)
{
// null is not supported.
stateData.Cursor = MessagePackSerializer.SerializeUnicodeString(stateData.Buffer, stateData.Cursor, scopeItem.Key);
stateData.Cursor = MessagePackSerializer.Serialize(stateData.Buffer, stateData.Cursor, scopeItem.Value);
stateData.FieldsCount += 1;
}
}
else
{
stateData.HasEnvProperties = true;
}
}
};

private static readonly Action<LogRecordScope, MsgPackLogExporter> ProcessScopeForEnvProperties = (scope, state) =>
{
var stateData = state.m_serializationData.Value;
var customFields = state.m_customFields;

foreach (KeyValuePair<string, object> scopeItem in scope)
{
if (string.IsNullOrEmpty(scopeItem.Key) || scopeItem.Key == "{OriginalFormat}")
{
continue;
}

if (!customFields.ContainsKey(scopeItem.Key))
{
stateData.Cursor = MessagePackSerializer.SerializeUnicodeString(stateData.Buffer, stateData.Cursor, scopeItem.Key);
stateData.Cursor = MessagePackSerializer.Serialize(stateData.Buffer, stateData.Cursor, scopeItem.Value);
stateData.EnvPropertiesCount += 1;
}
}
};

private class SerializationDataForScopes
{
public bool HasEnvProperties;
public ushort EnvPropertiesCount;

public int Cursor;
public byte[] Buffer;
public ushort FieldsCount;
}
}
2 changes: 1 addition & 1 deletion src/OpenTelemetry.Exporter.Geneva/MsgPackExporter/MsgPackTraceExporter.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -397,7 +397,7 @@ public void Dispose()

private const int BUFFER_SIZE = 65360; // the maximum ETW payload (inclusive)

private readonly ThreadLocal<byte[]> m_buffer = new ThreadLocal<byte[]>(() => null);
private readonly ThreadLocal<byte[]> m_buffer = new(() => null);

private readonly byte[] m_bufferPrologue;

Expand Down
53 changes: 18 additions & 35 deletions test/OpenTelemetry.Exporter.Geneva.Benchmark/Exporter/LogExporterBenchmarks.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,42 +20,25 @@
using OpenTelemetry.Logs;

/*
BenchmarkDotNet=v0.13.1, OS=Windows 10.0.22621
BenchmarkDotNet=v0.13.2, OS=Windows 11 (10.0.22621.819)
Intel Core i7-9700 CPU 3.00GHz, 1 CPU, 8 logical and 8 physical cores
.NET SDK=7.0.100-preview.6.22352.1
[Host] : .NET 6.0.9 (6.0.922.41905), X64 RyuJIT
DefaultJob : .NET 6.0.9 (6.0.922.41905), X64 RyuJIT

Without Scopes

| Method | IncludeFormattedMessage | Mean | Error | StdDev | Gen 0 | Allocated |
|-------------------------- |------------------------ |-----------:|--------:|--------:|-------:|----------:|
| LoggerWithMessageTemplate | False | 1,273.1 ns | 6.09 ns | 5.39 ns | 0.0362 | 232 B |
| LoggerWithDirectLoggerAPI | False | 1,213.0 ns | 9.71 ns | 8.61 ns | 0.0572 | 368 B |
| LoggerWithSourceGenerator | False | 1,243.5 ns | 6.13 ns | 5.44 ns | 0.0305 | 192 B |
| SerializeLogRecord | False | 587.7 ns | 2.71 ns | 2.54 ns | - | - |
| Export | False | 955.0 ns | 5.46 ns | 5.11 ns | - | - |
| LoggerWithMessageTemplate | True | 1,261.1 ns | 6.59 ns | 5.84 ns | 0.0362 | 232 B |
| LoggerWithDirectLoggerAPI | True | 1,214.4 ns | 4.56 ns | 4.27 ns | 0.0572 | 368 B |
| LoggerWithSourceGenerator | True | 1,229.6 ns | 6.84 ns | 6.40 ns | 0.0305 | 192 B |
| SerializeLogRecord | True | 581.6 ns | 2.38 ns | 2.11 ns | - | - |
| Export | True | 958.4 ns | 3.02 ns | 2.52 ns | - | - |


With Scopes (https://github.com/open-telemetry/opentelemetry-dotnet-contrib/pull/545)

| Method | IncludeFormattedMessage | Mean | Error | StdDev | Gen 0 | Allocated |
|-------------------------- |------------------------ |-----------:|--------:|--------:|-------:|----------:|
| LoggerWithMessageTemplate | False | 1,280.8 ns | 7.45 ns | 6.61 ns | 0.0534 | 336 B |
| LoggerWithDirectLoggerAPI | False | 1,261.5 ns | 6.38 ns | 5.96 ns | 0.0744 | 472 B |
| LoggerWithSourceGenerator | False | 1,309.3 ns | 4.83 ns | 4.52 ns | 0.0458 | 296 B |
| SerializeLogRecord | False | 611.3 ns | 4.63 ns | 4.11 ns | 0.0162 | 104 B |
| Export | False | 1,012.2 ns | 7.56 ns | 7.07 ns | 0.0153 | 104 B |
| LoggerWithMessageTemplate | True | 1,278.3 ns | 6.63 ns | 5.88 ns | 0.0534 | 336 B |
| LoggerWithDirectLoggerAPI | True | 1,263.8 ns | 8.26 ns | 7.73 ns | 0.0744 | 472 B |
| LoggerWithSourceGenerator | True | 1,273.4 ns | 5.57 ns | 5.21 ns | 0.0458 | 296 B |
| SerializeLogRecord | True | 604.3 ns | 2.83 ns | 2.65 ns | 0.0162 | 104 B |
| Export | True | 1,003.6 ns | 9.29 ns | 8.69 ns | 0.0153 | 104 B |
.NET SDK=7.0.100
[Host] : .NET 6.0.11 (6.0.1122.52304), X64 RyuJIT AVX2
DefaultJob : .NET 6.0.11 (6.0.1122.52304), X64 RyuJIT AVX2


| Method | IncludeFormattedMessage | Mean | Error | StdDev | Gen0 | Allocated |
|-------------------------- |------------------------ |---------:|--------:|--------:|-------:|----------:|
| LoggerWithMessageTemplate | False | 832.5 ns | 5.99 ns | 5.00 ns | 0.0162 | 104 B |
| LoggerWithDirectLoggerAPI | False | 766.2 ns | 3.85 ns | 3.60 ns | 0.0381 | 240 B |
| LoggerWithSourceGenerator | False | 815.3 ns | 2.89 ns | 2.41 ns | 0.0095 | 64 B |
| SerializeLogRecord | False | 582.3 ns | 0.81 ns | 0.72 ns | - | - |
| Export | False | 646.0 ns | 1.10 ns | 0.86 ns | - | - |
| LoggerWithMessageTemplate | True | 847.7 ns | 5.56 ns | 5.20 ns | 0.0162 | 104 B |
| LoggerWithDirectLoggerAPI | True | 762.5 ns | 2.72 ns | 2.41 ns | 0.0381 | 240 B |
| LoggerWithSourceGenerator | True | 816.6 ns | 2.79 ns | 2.47 ns | 0.0095 | 64 B |
| SerializeLogRecord | True | 586.3 ns | 1.80 ns | 1.69 ns | - | - |
| Export | True | 659.5 ns | 6.00 ns | 5.61 ns | - | - |
*/

namespace OpenTelemetry.Exporter.Geneva.Benchmark;
Expand Down