Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
4 changes: 4 additions & 0 deletions src/OpenTelemetry/CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,10 @@ Notes](../../RELEASENOTES.md).
time at runtime.
([#7760](https://github.com/open-telemetry/opentelemetry-dotnet/pull/7760))

* Fixed lazy logger provider builds after a failure from reusing partially
initialized provider state.
([#7761](https://github.com/open-telemetry/opentelemetry-dotnet/pull/7761))

## 1.18.0

Released 2026-Aug-21
Expand Down
30 changes: 30 additions & 0 deletions src/OpenTelemetry/Logs/Builder/LoggerProviderBuilderSdk.cs
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
// Copyright The OpenTelemetry Authors
// SPDX-License-Identifier: Apache-2.0

using System.Runtime.ExceptionServices;
using Microsoft.Extensions.DependencyInjection;
using OpenTelemetry.Resources;

Expand All @@ -14,6 +15,7 @@ internal sealed class LoggerProviderBuilderSdk : LoggerProviderBuilder, ILoggerP
private const string DefaultInstrumentationVersion = "1.0.0.0";

private readonly IServiceProvider serviceProvider;
private ExceptionDispatchInfo? providerBuildException;
private LoggerProviderSdk? loggerProvider;

public LoggerProviderBuilderSdk(IServiceProvider serviceProvider)
Expand All @@ -31,6 +33,8 @@ public LoggerProviderBuilderSdk(IServiceProvider serviceProvider)

public void RegisterProvider(LoggerProviderSdk loggerProvider)
{
this.providerBuildException?.Throw();

if (this.loggerProvider != null)
{
throw new NotSupportedException("LoggerProvider cannot be accessed while build is executing.");
Expand All @@ -39,6 +43,32 @@ public void RegisterProvider(LoggerProviderSdk loggerProvider)
this.loggerProvider = loggerProvider;
}

public void HandleProviderBuildFailure(LoggerProviderSdk loggerProvider, Exception exception)
{
if (ReferenceEquals(this.loggerProvider, loggerProvider))
{
this.loggerProvider = null;

// Processors and instrumentations are disposed when provider
// construction fails. If any were added, retrying would either
// reuse disposed instances or lose configuration that was
// transferred destructively from OpenTelemetryLoggerOptions.
if (this.Processors.Count != 0
|| this.Instrumentation.Count != 0
|| this.ResourceBuilder != null)
{
this.providerBuildException = ExceptionDispatchInfo.Capture(exception);
}
}
}

public void ResetBuildState()
{
this.Processors.Clear();
this.Instrumentation.Clear();
this.ResourceBuilder = null;
}

public override LoggerProviderBuilder AddInstrumentation<TInstrumentation>(Func<TInstrumentation> instrumentationFactory)
{
var instance = instrumentationFactory();
Expand Down
72 changes: 72 additions & 0 deletions src/OpenTelemetry/Logs/ILogger/DeferredOpenTelemetryLogger.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,72 @@
// Copyright The OpenTelemetry Authors
// SPDX-License-Identifier: Apache-2.0

using Microsoft.Extensions.Logging;

namespace OpenTelemetry.Logs;

internal sealed class DeferredOpenTelemetryLogger : ILogger
{
private readonly string categoryName;
private readonly OpenTelemetryLoggerProvider loggerProvider;
private readonly Lock syncObject = new();
private LoggerState? loggerState;

public DeferredOpenTelemetryLogger(
OpenTelemetryLoggerProvider loggerProvider,
string categoryName)
{
this.loggerProvider = loggerProvider;
this.categoryName = categoryName;
}

public IDisposable BeginScope<TState>(TState state)
where TState : notnull => this.loggerProvider.ScopeProvider?.Push(state) ?? NullScope.Instance;

public bool IsEnabled(LogLevel logLevel)
=> logLevel != LogLevel.None && !Sdk.SuppressInstrumentation;

public void Log<TState>(
LogLevel logLevel,
EventId eventId,
TState state,
Exception? exception,
Func<TState, Exception?, string> formatter)
{
this.GetLogger()?.Log(logLevel, eventId, state, exception, formatter);
}

private OpenTelemetryLogger? GetLogger()
{
if (this.loggerProvider.Provider is not LoggerProviderSdk loggerProviderSdk)
{
return null;
}

var loggerState = Volatile.Read(ref this.loggerState);
if (loggerState == null || !ReferenceEquals(loggerState.Provider, loggerProviderSdk))
{
lock (this.syncObject)
{
loggerState = this.loggerState;
if (loggerState == null || !ReferenceEquals(loggerState.Provider, loggerProviderSdk))
{
loggerState = new(
loggerProviderSdk,
new OpenTelemetryLogger(loggerProviderSdk, this.loggerProvider.Options, this.categoryName));
Volatile.Write(ref this.loggerState, loggerState);
}
}
}

loggerState.Logger.ScopeProvider = this.loggerProvider.ScopeProvider;
return loggerState.Logger;
}

private sealed class LoggerState(LoggerProviderSdk provider, OpenTelemetryLogger logger)
{
public OpenTelemetryLogger Logger { get; } = logger;

public LoggerProviderSdk Provider { get; } = provider;
}
}
17 changes: 17 additions & 0 deletions src/OpenTelemetry/Logs/ILogger/NullScope.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,17 @@
// Copyright The OpenTelemetry Authors
// SPDX-License-Identifier: Apache-2.0

namespace OpenTelemetry.Logs;

internal sealed class NullScope : IDisposable
{
private NullScope()
{
}

public static NullScope Instance { get; } = new();

public void Dispose()
{
}
}
9 changes: 0 additions & 9 deletions src/OpenTelemetry/Logs/ILogger/OpenTelemetryLogger.cs
Original file line number Diff line number Diff line change
Expand Up @@ -229,13 +229,4 @@ private static bool TryGetOriginalFormatFromAttributes(
originalFormat = null;
return false;
}

private sealed class NullScope : IDisposable
{
public static NullScope Instance { get; } = new();

public void Dispose()
{
}
}
}
26 changes: 20 additions & 6 deletions src/OpenTelemetry/Logs/ILogger/OpenTelemetryLoggerProvider.cs
Original file line number Diff line number Diff line change
Expand Up @@ -96,8 +96,15 @@ internal LoggerProvider Provider
// it is intentionally left in place so the next access
// retries instead of caching the failure.
provider = this.loggerProviderFactory!();
Volatile.Write(ref this.provider, provider);
this.loggerProviderFactory = null;

// A provider which is still being built may be returned to
// break an ILoggerFactory circular dependency. Do not cache
// it until construction has completed successfully.
if (provider is not LoggerProviderSdk { IsBuilt: false })
{
Volatile.Write(ref this.provider, provider);
this.loggerProviderFactory = null;
}
}

return provider;
Expand Down Expand Up @@ -141,12 +148,19 @@ public ILogger CreateLogger(string categoryName)
logger = (this.loggers[categoryName] as ILogger)!;
if (logger == null)
{
logger = this.Provider is not LoggerProviderSdk loggerProviderSdk
? NullLogger.Instance
: new OpenTelemetryLogger(loggerProviderSdk, this.Options, categoryName)
var provider = this.Provider;
logger = provider switch
{
LoggerProviderSdk { IsBuilt: true } loggerProviderSdk => new OpenTelemetryLogger(
loggerProviderSdk,
this.Options,
categoryName)
{
ScopeProvider = this.ScopeProvider,
};
},
LoggerProviderSdk => new DeferredOpenTelemetryLogger(this, categoryName),
_ => NullLogger.Instance,
};

this.loggers[categoryName] = logger;
}
Expand Down
8 changes: 7 additions & 1 deletion src/OpenTelemetry/Logs/LoggerProviderSdk.cs
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ internal sealed class LoggerProviderSdk : LoggerProvider
internal IDisposable? OwnedServiceProvider;
internal bool Disposed;
internal int ShutdownCount;
private int isBuilt;
private ILogRecordPool? threadStaticPool = LogRecordThreadStaticPool.Instance;

public LoggerProviderSdk(
Expand Down Expand Up @@ -76,10 +77,13 @@ public LoggerProviderSdk(
}

OpenTelemetrySdkEventSource.Log.LoggerProviderSdkEvent("LoggerProviderSdk built successfully.");
Volatile.Write(ref this.isBuilt, 1);
}
catch (Exception)
catch (Exception ex)
{
state.HandleProviderBuildFailure(this, ex);
this.DisposeBuiltState(state);
state.ResetBuildState();
throw;
}
}
Expand All @@ -92,6 +96,8 @@ public LoggerProviderSdk(

public ILogRecordPool LogRecordPool => this.threadStaticPool ?? LogRecordSharedPool.Current;

internal bool IsBuilt => Volatile.Read(ref this.isBuilt) != 0;

public static bool ContainsBatchProcessor(BaseProcessor<LogRecord> processor)
{
if (processor is BatchExportProcessor<LogRecord>)
Expand Down
120 changes: 120 additions & 0 deletions test/OpenTelemetry.Tests/Logs/OpenTelemetryLoggingExtensionsTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -303,6 +303,117 @@ public void CircularReferenceTest(bool requestLoggerProviderDirectly)
Assert.IsType<TestLogProcessorWithILoggerFactoryDependency>(loggerProvider.Processor);
}

[Fact]
public void LazyProviderRetriesAfterFailedBuildTest()
{
var configureInvocationCount = 0;
TestLogProcessor? configuredProcessor = null;
var services = new ServiceCollection();

services.AddLogging(logging => logging.AddOpenTelemetry());

services.ConfigureOpenTelemetryLoggerProvider((sp, builder) =>
{
if (Interlocked.Increment(ref configureInvocationCount) == 1)
{
throw new InvalidOperationException("The first logger provider build is expected to fail.");
}

configuredProcessor = new TestLogProcessor();
builder.AddProcessor(configuredProcessor);
});

using var serviceProvider = services.BuildServiceProvider();
var loggerFactory = serviceProvider.GetRequiredService<ILoggerFactory>();

Assert.Throws<InvalidOperationException>(() => loggerFactory.CreateLogger("FirstLogger"));

var logger = loggerFactory.CreateLogger("SecondLogger");
logger.Log(
LogLevel.Information,
new EventId(1),
"This record should be processed.",
exception: null,
static (state, _) => state);

var processor = Assert.IsType<TestLogProcessor>(configuredProcessor);
Assert.Equal(2, configureInvocationCount);
Assert.Equal(1, processor.OnEndCount);
}

[Fact]
public void LazyProviderDoesNotRetryAfterFailedBuildMutatesBuilderStateTest()
{
var configureInvocationCount = 0;
#pragma warning disable CA2000 // Dispose objects before losing scope
var processor = new TestLogProcessor();
#pragma warning restore CA2000 // Dispose objects before losing scope
var services = new ServiceCollection();

services.AddLogging(logging => logging.AddOpenTelemetry());

services.ConfigureOpenTelemetryLoggerProvider((sp, builder) =>
{
configureInvocationCount++;
builder.AddProcessor(processor);
throw new InvalidOperationException("The logger provider build is expected to fail.");
});

using var serviceProvider = services.BuildServiceProvider();
var loggerFactory = serviceProvider.GetRequiredService<ILoggerFactory>();

var firstException = Assert.Throws<InvalidOperationException>(
() => loggerFactory.CreateLogger("FirstLogger"));

Assert.True(processor.Disposed);

var secondException = Assert.Throws<InvalidOperationException>(
() => loggerFactory.CreateLogger("SecondLogger"));

Assert.Same(firstException, secondException);
Assert.Equal(1, configureInvocationCount);
}

[Fact]
public void LazyProviderRetriesAfterReentrantFailedBuildTest()
{
var configureInvocationCount = 0;
TestLogProcessor? configuredProcessor = null;
ILogger? reentrantLogger = null;
var services = new ServiceCollection();

services.AddLogging(logging => logging.AddOpenTelemetry());

services.ConfigureOpenTelemetryLoggerProvider((sp, builder) =>
{
if (Interlocked.Increment(ref configureInvocationCount) == 1)
{
reentrantLogger = sp.GetRequiredService<ILoggerFactory>().CreateLogger("ReentrantLogger");
throw new InvalidOperationException("The first logger provider build is expected to fail.");
}

configuredProcessor = new TestLogProcessor();
builder.AddProcessor(configuredProcessor);
});

using var serviceProvider = services.BuildServiceProvider();
var loggerFactory = serviceProvider.GetRequiredService<ILoggerFactory>();

Assert.Throws<InvalidOperationException>(() => loggerFactory.CreateLogger("FirstLogger"));

var logger = Assert.IsAssignableFrom<ILogger>(reentrantLogger);
logger.Log(
LogLevel.Information,
new EventId(1),
"This record should be processed after the retry.",
exception: null,
static (state, _) => state);

var processor = Assert.IsType<TestLogProcessor>(configuredProcessor);
Assert.Equal(2, configureInvocationCount);
Assert.Equal(1, processor.OnEndCount);
}

[Theory]
[InlineData(true, false)]
[InlineData(false, true)]
Expand Down Expand Up @@ -388,6 +499,15 @@ private sealed class TestLogProcessor : BaseProcessor<LogRecord>
{
public bool Disposed;

public int OnEndCount;

public override void OnEnd(LogRecord data)
{
this.OnEndCount++;

base.OnEnd(data);
}

protected override void Dispose(bool disposing)
{
this.Disposed = true;
Expand Down
Loading