[Exporter.Geneva] Add support for ILogger scopes

[utpilla]

A potential approach to fix #389

Changes

• Add support for exporting ILogger scopes

Note:

This PR demonstrates one possible way of exporting scopes. We would release a beta package with this feature to gather feedback.

Example1:

using (logger.BeginScope("MyScope"))
{
    logger.LogInformation("Hello from {food} {price}.", "artichoke", 3.99);
}

Output:
Same table as before, with an additional column "Scopes", which will be a list of 1 element. That element is a Map with 1 key value pair. with "scope", ""MyScope" as values.

Example2:

using (logger.BeginScope("MyOuterScope"))
using (logger.BeginScope("MyInnerScope"))
{
    logger.LogInformation("Hello from {food} {price}.", "artichoke", 3.99);
}

Output:
Same table as before, with an additional column "Scopes", which will be a list of 2 elements. Each element is a Map with 1 key value pair. with {"scope", ""MyOuterScope"}, {"scope", ""MyInnerScope"}, as values respectively .

Example 3: (using formatted string in Scopes)

using (logger.BeginScope("MyOuterScope"))
using (logger.BeginScope("MyInnerScope"))
using (logger.BeginScope("MyInnerInnerScope with {name} and {age} of custom", "John Doe", 35))
{
    logger.LogInformation("Hello from {food} {price}.", "artichoke", 3.99);
}

Same table as before, with an additional column "Scopes", which will be a list of 3 elements. Elements 1 and 2 is a Map with 1 key value pair. with {"scope", ""MyOuterScope"}, {"scope", ""MyInnerScope"}, as values respectively .
Element3 is a Map with 3 key value pairs, {""name"":""John Doe"",""age"":35,""{OriginalFormat}"":""MyInnerInnerScope with {name} and {age} of custom""}

Example 4: (using IReadOnlyList<KeyValuePair<string, object>> in scopes)

using (logger.BeginScope("MyOuterScope"))
using (logger.BeginScope("MyInnerScope"))
using (logger.BeginScope(new List<KeyValuePair<string, object>> { new KeyValuePair<string, object>("MyKey", "MyValue") }))
{
    logger.LogInformation("Hello from {food} {price}.", "artichoke", 3.99);
}

Same table as before, with an additional column "Scopes", which will be a list of 3 elements. Elements 1 and 2 is a Map with 1 key value pair. with {"scope", ""MyOuterScope"}, {"scope", ""MyInnerScope"}, as values respectively .
Element3 is a Map with one key value pair: {"MyKey":"MyValue"}

For significant contributions please make sure you have completed the following items:

• Appropriate CHANGELOG.md updated for non-trivial changes

[codecov]

Codecov Report

Merging #390 (56c53e2) into main (3f7f1ae) will decrease coverage by 0.02%.
The diff coverage is 18.18%.

@@            Coverage Diff             @@
##             main     #390      +/-   ##
==========================================
- Coverage   22.33%   22.31%   -0.03%     
==========================================
  Files         148      148              
  Lines        4539     4561      +22     
==========================================
+ Hits         1014     1018       +4     
- Misses       3525     3543      +18     

Impacted Files	Coverage Δ
...OpenTelemetry.Exporter.Geneva/GenevaLogExporter.cs	84.54% <18.18%> (-6.92%)	⬇️

[cijothomas]

LGTM.
Could you include an example in the PR description where one uses IReadOnly....as scope?

using (_logger.BeginScope(new Dictionary<string, object> { ["MyKey"] = "MyValue" }))
{
_logger.LogError("An example of an Error level message");
}

[CodeBlanch]

FYI this is going to allocate a delegate. Could maybe get around that using a ThreadStatic. Something like this...

private sealed class ScopeForEachState
{
   public ushort ScopeDepth;
   public int IndexArrayLength; // Confusing name
   public byte[] Buffer;
}

[ThreadStatic]
private static ScopeForEachState scopeState;

var state = scopeState ??= new() { Buffer = buffer };

state.ScopeDepth = 0;
state.IndexArrayLength = 0;

logRecord.ForEachScope(ProcessScope, state);

if (state.ScopeDepth > 0)
{
        MessagePackSerializer.WriteUInt16(buffer, state.IndexArrayLength, state.ScopeDepth);
        cntFields += 1;
}

private static readonly Action<LogRecordScope, ScopeForEachState> ProcessScope = (logRecord, state) =>
{
           var buffer = state.Buffer;

            if (++state.ScopeDepth == 1)
            {
                cursor = MessagePackSerializer.SerializeAsciiString(buffer, cursor, "scopes");
                cursor = MessagePackSerializer.WriteArrayHeader(buffer, cursor, ushort.MaxValue);
                state.IndexArrayLength = cursor - 2;
            }

            cursor = MessagePackSerializer.WriteMapHeader(buffer, cursor, ushort.MaxValue);
            int indexMapSizeScope = cursor - 2;
            ushort keysCount = 0;

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

                cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, key);
                cursor = MessagePackSerializer.Serialize(buffer, cursor, scopeItem.Value);
                keysCount++;
            }

            MessagePackSerializer.WriteUInt16(buffer, indexMapSizeScope, keysCount);
};

[CodeBlanch]

We have private static readonly ThreadLocal<byte[]> m_buffer = new ThreadLocal<byte[]>(() => null); you could just expand that a little bit to be like ThreadLocal<ExporterState> and then use ExporterState to contain the buffer + the stuff you need for scopes. Basically fold everything you need onto the 1 ThreadLocal.

[utpilla]

Thanks @CodeBlanch ! I have created #391 to track this. I'll be merging this PR to do a beta release to gather feedback. I'll send out a separate PR to avoid allocation here.

[CodeBlanch]

@cijothomas Might want to do...

using (_logger.BeginScope(new List<KeyValuePair<string, object>> { new KeyValuePair<string, object>("MyKey", "MyValue") }))

...not...

using (_logger.BeginScope(new Dictionary<string, object> { ["MyKey"] = "MyValue" }))

Because Dictionary<TKey, TValue> doesn't implement IReadOnlyList<KeyValuePair<TKey, TValue>> it will end up in here and get wrapped: https://github.com/open-telemetry/opentelemetry-dotnet/blob/fa21e1e1ddb56b0b355d45f531f63ae175990ab9/src/OpenTelemetry/Logs/LogRecordScope.cs#L67

Oh ILogger API 🤦

[reyang]

Need to understand the design here:

1. What if there is a user-provided field called scopes?
2. Is this opt-in or opt-out?

[cijothomas]

2. Its opt-in, controlled by the SDK itself (https://github.com/open-telemetry/opentelemetry-dotnet/blob/main/src/OpenTelemetry/Logs/OpenTelemetryLoggerOptions.cs#L34-L38), and not Exporter.Geneva

[utpilla]

1. What if there is a user-provided field called scopes?

Then we would have two columns named scopes in the .csv. It would be interesting to know how it gets exported to Geneva.

[reyang]

1. What if there is a user-provided field called scopes?

Then we would have two columns named scopes in the .csv. It would be interesting to know how it gets exported to Geneva.

Does this sound like a bug (the user is doing all valid things and ended up with something invalid)?

[cijothomas]

Is this same issue as a name clash with prepopulatedfields, and one of activity/log attributes?
A user can add a prepopulated field (foo,bar), and do a log/trace with {foo,baz}..

[reyang]

Is this same issue as a name clash with prepopulatedfields, and one of activity/log attributes? A user can add a prepopulated field (foo,bar), and do a log/trace with {foo,baz}.

I think the key difference is that scopes is a field name that got introduced without the user giving the name explicitly.

[wyatt-troia-msft]

Is this still in beta?

[utpilla]

The behavior for exporting scopes has been changed from what this PR offered. Please refer to #736 to understand how GenevaExporter would export scopes.

The support for exporting scopes is now a part of the latest 1.4.0-rc1 GenevaExporter package. It would also be a part of the next stable 1.4.0 GenevaExporter package which would be released soon after 1.4.0 stable release of OpenTelemetry .NET SDK.

[wyatt-troia-msft]

I don't see that as an available version in VS NuGet package manager. How can I use 1.4.0-rc1?

[utpilla]

I don't see that as an available version in VS NuGet package manager. How can I use 1.4.0-rc1?

GenevaExporter packages have been getting published to NuGet for some time now. Here's the link to the package: https://www.nuget.org/packages/OpenTelemetry.Exporter.Geneva/1.4.0-rc.1

[wyatt-troia-msft]

Can you see that version in your own Visual Studio's NuGet package manager? Even when I manually specify that version in my CS proj, the build fails.

error NU1102: Unable to find package OpenTelemetry.Exporter.Geneva with version (>= 1.4.0-rc1)

[wyatt-troia-msft]

@utpilla Are you still planning to release this as part of a stable version by the end of December?

[utpilla]

@wyatt-troia-msft As I mentioned in my previous comment, the support for exporting scopes would be a part of the next stable release of GenevaExporter. It's currently scheduled to be released in Jan end/ early Feb next year. You can track this milestone created for GenevaExporter 1.4.0 release: https://github.com/open-telemetry/opentelemetry-dotnet-contrib/milestone/1

[wyatt-troia-msft]

Thanks. Ok, I'm just trying to get a sense of timing, since you posted in the SDK Teams channel on Nov 16 that the scope-supporting stable release would happen by the end of the year. How confident are you in that new release timeframe (by early Feb) being accurate?

Not having correlation IDs in our Geneva logs (what my team wants to use scopes for) is a big problem for us, so if this is something we can be confident in having an easy fix for through scopes in the next month or two, we can probably wait, but if this is the sort of deadline that is likely to be delayed repeatedly, we will begin work sooner rather than later on a different, more manual fix.