[bug] BaseProcessor<LogRecord>.OnEnd gets invoked after it has been disposed.

[wouterroos]

Package

OpenTelemetry

Package Version

Package Name	Version
OpenTelemetry.Api	1.9.0
OpenTelemetry	1.9.0

Runtime Version

net8.0

Description

Hi,

I'm having an issue where a custom BaseProcessor<LogRecord>.OnEnd implementation is invoked after the instance has been disposed. I do not have a perfect reproduction scenario, as it seems to be a race condition of some sort, the log record it fails on during my test run does have a consistent category and body:

Category: "Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets" Body: "Connection id \"{ConnectionId}\" received FIN."

I can't say if the above log record is (indirectly) produced by our code or the OpenTelemetry SDK, as the stack trace (see Additional Context) does not provide that information.

I can't reproduce the issue if I override OnStart, but that is not a viable option for our implementation.

I tried working around the issue by registering the processor using:

SomeLogRecordProcessor processor = new SomeLogRecordProcessor();
loggerProviderBuilder.AddProcessor(processor);

Instead of:

loggerProviderBuilder.AddProcessor<SomeLogRecordProcessor>();

I was hoping that would give me ownership of the object. Unfortunately, it doesn't, as the SDK disposes of the object regardless of whether it was created by the SDK or the caller.

Any help would be greatly appreciated!

Steps to Reproduce

• Implement a custom BaseProcessor<LogRecord> like below to throw when OnEnd is invoked after Dispose:

public class SomeLogRecordProcessor : BaseProcessor<LogRecord>
{
    private bool _disposed;

    public override OnEnd(LogRecord data)
    {
        if (_disposed)
        {
            throw new ObjectDisposedException();
        }
    }

    protected override void Dispose(bool disposing)
    {
        if (disposing)
        {
            _disposed = true;
        }
    }
}

Expected Result

OnEnd is never called after the object has been disposed.

Actual Result

OnEnd is called after the object has been disposed.

Additional Context

Call stack:

[TimothyMothra]

Unfortunately we would need a repro to be able to investigate this. All the code you've shared looks valid.

Are you manually disposing the OpenTelemetry SDK? Assuming this is an ASP.NET CORE application, I would expect this to be initialized as part of startup and disposed as part of your application shutdown.

[cijothomas]

See https://github.com/open-telemetry/opentelemetry-dotnet/issues/1848

[wouterroos]

Thanks for the response, I've had a look at #1848 and that doesn't seem applicable. We're looking into disposal as @TimothyMothra mentioned, will let you know if we find something!