dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
14.63k stars 4.57k forks source link

[Microsoft.Extensions.Diagnostics] MetricsSubscriptionManager.Dispose not called #94434

Closed CodeBlanch closed 8 months ago

CodeBlanch commented 8 months ago

I'm working on implementing IMetricsListener inside OpenTelemetry .NET. I noticed writing unit tests that some tests work when run alone but fail when run with other tests.

It seems to be caused by MetricsSubscriptionManager.Dispose NOT being called when the host is disposed because MetricsSubscriptionManager does NOT implement IDisposable.

/cc @Tratcher @noahfalk

noahfalk commented 8 months ago

Was there a good example test that fails because of this? It certainly sounds like a bug we'd want to fix but I'm trying to figure out if this is 'get it fixed in servicing ASAP' or 'get it fixed in .NET 9'. I would imagine that most metrics stop producing data when the host is disposed which might mitigate the issue.

Thanks @CodeBlanch!

CodeBlanch commented 8 months ago

I agree with you @noahfalk I don't think the impact is big. For the normal usage where an app only has a single host/container everything will be fine.

I did force a call to MetricsSubscriptionManager.Dispose in my test suite and my issue(s) went away: https://github.com/CodeBlanch/opentelemetry-dotnet/blob/24322e8b7157ac694b24c77cdf63f3270d28bd74/test/OpenTelemetry.Tests/Metrics/MetricTestsBase.cs#L210

I'll try to distill my issue down to something more simple/easily repeatable for you ~tomorrow.

CodeBlanch commented 8 months ago

@noahfalk

Here's a repro. There are 2 tests each will pass when run alone but will fail when run together.

I didn't spend much time digging into it, but my guess is MetricsSubscriptionManager adds a listener which doesn't get removed when the host disposes.

Code ```csharp using System.Collections.Concurrent; using System.Diagnostics.Metrics; using System.Diagnostics.Tracing; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Diagnostics.Metrics; using Microsoft.Extensions.Hosting; using Xunit; namespace MetricsSubscriptionManager.Tests; public class MetricsSubscriptionManagerTests { [Fact] public void CounterPublishedTest() { using var host = CreateHost("TestMeter"); using var eventListener = new TestMetericsListenerEventListener(); using var meter = new Meter("TestMeter"); var counter = meter.CreateCounter("TestCounter"); counter.Add(1); Assert.Single(eventListener.Events); } [Fact] public void HistogramPublishedTest() { using var host = CreateHost("TestMeter"); using var eventListener = new TestMetericsListenerEventListener(); using var meter = new Meter("TestMeter"); var histogram = meter.CreateHistogram("TestHistogram"); histogram.Record(1); Assert.Single(eventListener.Events); } private static IDisposable CreateHost(string meterName) { var hostBuilder = new HostBuilder(); hostBuilder.ConfigureServices(services => { services.AddMetrics(metrics => metrics .EnableMetrics(meterName) .AddListener()); }); var host = hostBuilder.Build(); host.Start(); return host; } private sealed class TestMetericsListener : IMetricsListener { public string Name => nameof(TestMetericsListener); public MeasurementHandlers GetMeasurementHandlers() => new(); public void Initialize(IObservableInstrumentsSource source) { } public bool InstrumentPublished(Instrument instrument, out object userState) { TestMetericsListenerEventSource.Log.InstrumentPublished(instrument.Meter.Name, instrument.Name); userState = null; return true; } public void MeasurementsCompleted(Instrument instrument, object userState) { } } [EventSource(Name = nameof(TestMetericsListener))] private sealed class TestMetericsListenerEventSource : EventSource { public static TestMetericsListenerEventSource Log { get; } = new(); [Event(1, Message = "Instrument published: MeterName='{0}' InstrumentName='{1}'", Level = EventLevel.Informational)] public void InstrumentPublished(string meterName, string instrumentName) { this.WriteEvent(1, meterName, instrumentName); } } private sealed class TestMetericsListenerEventListener : EventListener { public TestMetericsListenerEventListener() { this.EnableEvents(TestMetericsListenerEventSource.Log, EventLevel.Informational); } public ConcurrentQueue Events { get; } = new(); protected override void OnEventWritten(EventWrittenEventArgs eventData) { this.Events.Enqueue(eventData); } } } ```
noahfalk commented 8 months ago

I did some quick debugging and confirmed I see a listener object that was created from the first test's host calling InstrumentPublished during the 2nd test. As you described, it appears that the listener should have gotten disconnected when the host was disposed but that didn't happen.

I think this repro below might be a little easier to work with. The expected behavior is that all the asserts pass. The actual behavior is that only the first assert passes and the remaining three after the comment fail.

static void Main(string[] args)
{
    var meter = new Meter("TestMeter");
    Counter<long> counter = null;

    var hostBuilder = new HostBuilder();

    hostBuilder.ConfigureServices(services =>
    {
        services.AddMetrics(metrics => metrics
            .EnableMetrics("TestMeter")
            .AddListener<TestMetricsListener>());
    });

    using (var host = hostBuilder.Build())
    {
        host.Start();
        counter = meter.CreateCounter<long>("TestCounter");
        Debug.Assert(TestMetricsListener.PublishCount == 1);
    }

    // the host has been disposed. This should have signaled MeasurementsCompleted,
    // stopped the listener from receiving new notifications, and make the counter
    // report that it is no longer enabled
    Debug.Assert(!counter.Enabled);
    Debug.Assert(TestMetricsListener.CompleteCount == 1);
    var counter2 = meter.CreateCounter<long>("TestCounter2");
    Debug.Assert(TestMetricsListener.PublishCount == 1);
}

class TestMetricsListener : IMetricsListener
{
    public static int PublishCount = 0;
    public static int CompleteCount = 0;
    public string Name => nameof(TestMetricsListener);

    public MeasurementHandlers GetMeasurementHandlers() => new();

    public void Initialize(IObservableInstrumentsSource source) { }

    public bool InstrumentPublished(Instrument instrument, out object userState)
    {
        PublishCount++;
        userState = null;
        return true;
    }

    public void MeasurementsCompleted(Instrument instrument, object userState)
    {
        CompleteCount++;
    }
}