diff --git a/src/Microsoft.Diagnostics.Monitoring.EventPipe/Counters/TraceEventExtensions.cs b/src/Microsoft.Diagnostics.Monitoring.EventPipe/Counters/TraceEventExtensions.cs index 7bd7e3611a..d6833da307 100644 --- a/src/Microsoft.Diagnostics.Monitoring.EventPipe/Counters/TraceEventExtensions.cs +++ b/src/Microsoft.Diagnostics.Monitoring.EventPipe/Counters/TraceEventExtensions.cs @@ -37,20 +37,64 @@ internal record struct ProviderAndCounter(string ProviderName, string CounterNam internal static class TraceEventExtensions { private static Dictionary counterMetadataByName = new(); + private static Dictionary counterMetadataById = new(); private static HashSet inactiveSharedSessions = new(StringComparer.OrdinalIgnoreCase); - // This assumes uniqueness of provider/counter combinations; - // this is currently a limitation (see https://github.com/dotnet/runtime/issues/93097 and https://github.com/dotnet/runtime/issues/93767) - public static CounterMetadata GetCounterMetadata(string providerName, string counterName, string meterTags = null, string instrumentTags = null, string scopeHash = null) + private static CounterMetadata AddCounterMetadata(string providerName, string counterName, int? id, string meterTags, string instrumentTags, string scopeHash) { + CounterMetadata metadata; + if (id.HasValue && counterMetadataById.TryGetValue(id.Value, out metadata)) + { + return metadata; + } + + // Its possible that we previously indexed this counter by name but it didn't have an ID at that point because we weren't + // listening to it then. + // Its also possible that we previously indexed a counter with the same name as this one but with different tags or scope hash. ProviderAndCounter providerAndCounter = new(providerName, counterName); - if (counterMetadataByName.TryGetValue(providerAndCounter, out CounterMetadata provider)) + if (counterMetadataByName.TryGetValue(providerAndCounter, out metadata)) { - return provider; + // we found a counter that matches the name, but it might not match everything + if (metadata.MeterTags == meterTags && metadata.InstrumentTags == instrumentTags && metadata.ScopeHash == scopeHash) + { + // add the ID index if it didn't exist before + if (id.HasValue) + { + counterMetadataById.TryAdd(id.Value, metadata); + } + return metadata; + } } - counterMetadataByName.Add(providerAndCounter, new CounterMetadata(providerName, counterName, meterTags, instrumentTags, scopeHash)); - return counterMetadataByName[providerAndCounter]; + // no pre-existing counter metadata was found, create a new one + metadata = new CounterMetadata(providerName, counterName, meterTags, instrumentTags, scopeHash); + if (id.HasValue) + { + counterMetadataById.TryAdd(id.Value, metadata); + } + counterMetadataByName.TryAdd(providerAndCounter, metadata); + return metadata; + } + + private static CounterMetadata GetCounterMetadata(string providerName, string counterName, int? id) + { + // Lookup by ID is preferred because it eliminates ambiguity in the case of duplicate provider/counter names. + // IDs are present starting in MetricsEventSource 9.0. + // Duplicate named providers/counters might still have different tags or scope hashes + CounterMetadata metadata; + if (id.HasValue && counterMetadataById.TryGetValue(id.Value, out metadata)) + { + return metadata; + } + ProviderAndCounter providerAndCounter = new(providerName, counterName); + if (counterMetadataByName.TryGetValue(providerAndCounter, out metadata)) + { + return metadata; + } + + // For EventCounter based events we expect to fall through here the first time a new counter is observed + // For MetricsEventSource events we should never reach here unless the BeginInstrumentRecording event was dropped. + return AddCounterMetadata(providerName, counterName, id, null, null, null); } public static bool TryGetCounterPayload(this TraceEvent traceEvent, CounterConfiguration counterConfiguration, out ICounterPayload payload) @@ -185,22 +229,29 @@ private static void HandleGauge(TraceEvent obj, CounterConfiguration counterConf string unit = (string)obj.PayloadValue(4); string tags = (string)obj.PayloadValue(5); string lastValueText = (string)obj.PayloadValue(6); + int? id = null; + + if (obj.Version >= 2) + { + id = (int)obj.PayloadValue(7); + } if (!counterConfiguration.CounterFilter.IsIncluded(meterName, instrumentName)) { return; } + CounterMetadata metadata = GetCounterMetadata(meterName, instrumentName, id); // the value might be an empty string indicating no measurement was provided this collection interval if (double.TryParse(lastValueText, NumberStyles.Number | NumberStyles.Float, CultureInfo.InvariantCulture, out double lastValue)) { - payload = new GaugePayload(GetCounterMetadata(meterName, instrumentName), null, unit, tags, lastValue, obj.TimeStamp); + payload = new GaugePayload(metadata, null, unit, tags, lastValue, obj.TimeStamp); } else { // for observable instruments we assume the lack of data is meaningful and remove it from the UI // this happens when the Gauge callback function throws an exception. - payload = new CounterEndedPayload(GetCounterMetadata(meterName, instrumentName), obj.TimeStamp); + payload = new CounterEndedPayload(metadata, obj.TimeStamp); } } @@ -223,18 +274,25 @@ private static void HandleBeginInstrumentReporting(TraceEvent traceEvent, Counte return; } - if (traceEvent.Version < 1) + string instrumentTags = null; + string meterTags = null; + string meterScopeHash = null; + int? instrumentID = null; + + if (traceEvent.Version >= 1) { - payload = new BeginInstrumentReportingPayload(GetCounterMetadata(meterName, instrumentName), traceEvent.TimeStamp); + instrumentTags = (string)traceEvent.PayloadValue(7); + meterTags = (string)traceEvent.PayloadValue(8); + meterScopeHash = (string)traceEvent.PayloadValue(9); } - else + if (traceEvent.Version >= 2) { - string instrumentTags = (string)traceEvent.PayloadValue(7); - string meterTags = (string)traceEvent.PayloadValue(8); - string meterScopeHash = (string)traceEvent.PayloadValue(9); - - payload = new BeginInstrumentReportingPayload(GetCounterMetadata(meterName, instrumentName, meterTags, instrumentTags, meterScopeHash), traceEvent.TimeStamp); + int id = (int)traceEvent.PayloadValue(10); + // ID zero is a sentinel value for MetricsEventSource events indicating no ID was provided because the instrument was not being listened to. + // Many different instruments may all share ID zero we don't want to index them by that ID. + instrumentID = (id != 0) ? id : null; } + payload = new BeginInstrumentReportingPayload(AddCounterMetadata(meterName, instrumentName, instrumentID, meterTags, instrumentTags, meterScopeHash), traceEvent.TimeStamp); } private static void HandleCounterRate(TraceEvent traceEvent, CounterConfiguration counterConfiguration, out ICounterPayload payload) @@ -256,27 +314,32 @@ private static void HandleCounterRate(TraceEvent traceEvent, CounterConfiguratio string rateText = (string)traceEvent.PayloadValue(6); //Starting in .NET 8 we also publish the absolute value of these counters string absoluteValueText = null; + int? id = null; if (traceEvent.Version >= 1) { absoluteValueText = (string)traceEvent.PayloadValue(7); } + if (traceEvent.Version >= 2) + { + id = (int)traceEvent.PayloadValue(8); + } if (!counterConfiguration.CounterFilter.IsIncluded(meterName, instrumentName)) { return; } - + CounterMetadata metadata = GetCounterMetadata(meterName, instrumentName, id); if (double.TryParse(rateText, NumberStyles.Number | NumberStyles.Float, CultureInfo.InvariantCulture, out double rate)) { if (absoluteValueText != null && counterConfiguration.UseCounterRateAndValuePayload && double.TryParse(absoluteValueText, NumberStyles.Number | NumberStyles.Float, CultureInfo.InvariantCulture, out double value)) { - payload = new CounterRateAndValuePayload(GetCounterMetadata(meterName, instrumentName), null, unit, tags, rate, value, traceEvent.TimeStamp); + payload = new CounterRateAndValuePayload(metadata, null, unit, tags, rate, value, traceEvent.TimeStamp); } else { - payload = new RatePayload(GetCounterMetadata(meterName, instrumentName), null, unit, tags, rate, counterConfiguration.CounterFilter.DefaultIntervalSeconds, traceEvent.TimeStamp); + payload = new RatePayload(metadata, null, unit, tags, rate, counterConfiguration.CounterFilter.DefaultIntervalSeconds, traceEvent.TimeStamp); } } else @@ -284,7 +347,7 @@ private static void HandleCounterRate(TraceEvent traceEvent, CounterConfiguratio // for observable instruments we assume the lack of data is meaningful and remove it from the UI // this happens when the ObservableCounter callback function throws an exception // or when the ObservableCounter doesn't include a measurement for a particular set of tag values. - payload = new CounterEndedPayload(GetCounterMetadata(meterName, instrumentName), traceEvent.TimeStamp); + payload = new CounterEndedPayload(metadata, traceEvent.TimeStamp); } } @@ -306,16 +369,22 @@ private static void HandleUpDownCounterValue(TraceEvent traceEvent, CounterConfi string tags = (string)traceEvent.PayloadValue(5); //string rateText = (string)traceEvent.PayloadValue(6); // Not currently using rate for UpDownCounters. string valueText = (string)traceEvent.PayloadValue(7); + int? id = null; + if (traceEvent.Version >= 2) + { + id = (int)traceEvent.PayloadValue(8); + } if (!configuration.CounterFilter.IsIncluded(meterName, instrumentName)) { return; } + CounterMetadata metadata = GetCounterMetadata(meterName, instrumentName, id); if (double.TryParse(valueText, NumberStyles.Number | NumberStyles.Float, CultureInfo.InvariantCulture, out double value)) { // UpDownCounter reports the value, not the rate - this is different than how Counter behaves. - payload = new UpDownCounterPayload(GetCounterMetadata(meterName, instrumentName), null, unit, tags, value, traceEvent.TimeStamp); + payload = new UpDownCounterPayload(metadata, null, unit, tags, value, traceEvent.TimeStamp); } else @@ -323,7 +392,7 @@ private static void HandleUpDownCounterValue(TraceEvent traceEvent, CounterConfi // for observable instruments we assume the lack of data is meaningful and remove it from the UI // this happens when the ObservableUpDownCounter callback function throws an exception // or when the ObservableUpDownCounter doesn't include a measurement for a particular set of tag values. - payload = new CounterEndedPayload(GetCounterMetadata(meterName, instrumentName), traceEvent.TimeStamp); + payload = new CounterEndedPayload(metadata, traceEvent.TimeStamp); } } @@ -344,6 +413,13 @@ private static void HandleHistogram(TraceEvent obj, CounterConfiguration configu string unit = (string)obj.PayloadValue(4); string tags = (string)obj.PayloadValue(5); string quantilesText = (string)obj.PayloadValue(6); + //int count - unused arg 7 + //double sum - unused arg 8 + int? id = null; + if (obj.Version >= 2) + { + id = (int)obj.PayloadValue(9); + } if (!configuration.CounterFilter.IsIncluded(meterName, instrumentName)) { @@ -352,8 +428,8 @@ private static void HandleHistogram(TraceEvent obj, CounterConfiguration configu //Note quantiles can be empty. IList quantiles = ParseQuantiles(quantilesText); - - payload = new AggregatePercentilePayload(GetCounterMetadata(meterName, instrumentName), null, unit, tags, quantiles, obj.TimeStamp); + CounterMetadata metadata = GetCounterMetadata(meterName, instrumentName, id); + payload = new AggregatePercentilePayload(metadata, null, unit, tags, quantiles, obj.TimeStamp); } private static void HandleHistogramLimitReached(TraceEvent obj, CounterConfiguration configuration, out ICounterPayload payload) diff --git a/src/tests/EventPipeTracee/DuplicateNameMetrics.cs b/src/tests/EventPipeTracee/DuplicateNameMetrics.cs new file mode 100644 index 0000000000..189bc194e2 --- /dev/null +++ b/src/tests/EventPipeTracee/DuplicateNameMetrics.cs @@ -0,0 +1,50 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using System.Diagnostics.Metrics; + + + +namespace EventPipeTracee +{ + // The constructor overloads for Meter and Counter that take tags were added in .NET 8.0 + // so this class is only available when built against 8.0 and later +#if NET8_0_OR_GREATER + internal sealed class DuplicateNameMetrics : IDisposable + { + private Meter _meter1; + private Meter _meter2; + private Counter _counter1a; + private Counter _counter1b; + private Counter _counter2a; + private Counter _counter2b; + + public DuplicateNameMetrics() + { + _meter1 = new Meter("AmbiguousNameMeter", "", [new("MeterTag", "one")]); + _meter2 = new Meter("AmbiguousNameMeter", "", [new("MeterTag", "two")]); + _counter1a = _meter1.CreateCounter("AmbiguousNameCounter", "", "", [new("InstrumentTag", "A")]); + _counter1b = _meter1.CreateCounter("AmbiguousNameCounter", "", "", [new("InstrumentTag", "B")]); + _counter2a = _meter2.CreateCounter("AmbiguousNameCounter", "", "", [new("InstrumentTag", "A")]); + _counter2b = _meter2.CreateCounter("AmbiguousNameCounter", "", "", [new("InstrumentTag", "B")]); + } + + + public void IncrementCounter(int v = 1) + { + _counter1a.Add(v); + _counter1b.Add(v + 1); + _counter2a.Add(v + 2); + _counter2b.Add(v + 3); + } + + public void Dispose() + { + _meter1?.Dispose(); + _meter2?.Dispose(); + } + } +#endif +} diff --git a/src/tests/EventPipeTracee/EventPipeTracee.csproj b/src/tests/EventPipeTracee/EventPipeTracee.csproj index ddd9ff2c29..f02e3fee9e 100644 --- a/src/tests/EventPipeTracee/EventPipeTracee.csproj +++ b/src/tests/EventPipeTracee/EventPipeTracee.csproj @@ -3,6 +3,7 @@ Exe $(BuildProjectFramework) $(BuildTargetFrameworks) + NET8_0_OR_GREATER diff --git a/src/tests/EventPipeTracee/Program.cs b/src/tests/EventPipeTracee/Program.cs index 1decd119a0..9c61e0db0f 100644 --- a/src/tests/EventPipeTracee/Program.cs +++ b/src/tests/EventPipeTracee/Program.cs @@ -32,8 +32,10 @@ public static async Task Main(string[] args) string loggerCategory = args[1]; bool diagMetrics = args.Any("DiagMetrics".Equals); + bool duplicateNameMetrics = args.Any("DuplicateNameMetrics".Equals); Console.WriteLine($"{pid} EventPipeTracee: DiagMetrics {diagMetrics}"); + Console.WriteLine($"{pid} EventPipeTracee: DuplicateNameMetrics {duplicateNameMetrics}"); Console.WriteLine($"{pid} EventPipeTracee: start process"); Console.Out.Flush(); @@ -60,8 +62,6 @@ public static async Task Main(string[] args) Console.WriteLine($"{pid} EventPipeTracee: {DateTime.UtcNow} Awaiting start"); Console.Out.Flush(); - using CustomMetrics metrics = diagMetrics ? new CustomMetrics() : null; - // Wait for server to send something int input = pipeStream.ReadByte(); @@ -70,10 +70,14 @@ public static async Task Main(string[] args) CancellationTokenSource recordMetricsCancellationTokenSource = new(); - if (diagMetrics) + if (diagMetrics || duplicateNameMetrics) { _ = Task.Run(async () => { + using CustomMetrics metrics = diagMetrics ? new CustomMetrics() : null; +#if NET8_0_OR_GREATER + using DuplicateNameMetrics dupMetrics = duplicateNameMetrics ? new DuplicateNameMetrics() : null; +#endif // Recording a single value appeared to cause test flakiness due to a race // condition with the timing of when dotnet-counters starts collecting and // when these values are published. Publishing values repeatedly bypasses this problem. @@ -81,8 +85,11 @@ public static async Task Main(string[] args) { recordMetricsCancellationTokenSource.Token.ThrowIfCancellationRequested(); - metrics.IncrementCounter(); - metrics.RecordHistogram(10.0f); + metrics?.IncrementCounter(); + metrics?.RecordHistogram(10.0f); +#if NET8_0_OR_GREATER + dupMetrics?.IncrementCounter(); +#endif await Task.Delay(1000).ConfigureAwait(true); } diff --git a/src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs b/src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs index 355324db2f..72852297c3 100644 --- a/src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs +++ b/src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs @@ -29,27 +29,42 @@ public EventCounterPipelineUnitTests(ITestOutputHelper output) _output = output; } + class ExpectedCounter + { + public string ProviderName { get; } + public string CounterName { get; } + public string MeterTags { get; } + public string InstrumentTags { get; } + + public ExpectedCounter(string providerName, string counterName, string meterTags = null, string instrumentTags = null) + { + ProviderName = providerName; + CounterName = counterName; + MeterTags = meterTags; + InstrumentTags = instrumentTags; + } + + public bool MatchesCounterMetadata(CounterMetadata metadata) + { + if (metadata.ProviderName != ProviderName) return false; + if (metadata.CounterName != CounterName) return false; + if (MeterTags != null && metadata.MeterTags != MeterTags) return false; + if (InstrumentTags != null && metadata.InstrumentTags != InstrumentTags) return false; + return true; + } + } + private sealed class TestMetricsLogger : ICountersLogger { - private readonly List _expectedCounters = new(); - private Dictionary _metrics = new(); + private readonly List _expectedCounters = new(); + private Dictionary _metrics = new(); private readonly TaskCompletionSource _foundExpectedCountersSource; - public TestMetricsLogger(IDictionary> expectedCounters, TaskCompletionSource foundExpectedCountersSource) + public TestMetricsLogger(IEnumerable expectedCounters, TaskCompletionSource foundExpectedCountersSource) { _foundExpectedCountersSource = foundExpectedCountersSource; - - if (expectedCounters.Count > 0) - { - foreach (string providerName in expectedCounters.Keys) - { - foreach (string counterName in expectedCounters[providerName]) - { - _expectedCounters.Add(CreateKey(providerName, counterName)); - } - } - } - else + _expectedCounters = new(expectedCounters); + if (_expectedCounters.Count == 0) { foundExpectedCountersSource.SetResult(null); } @@ -59,48 +74,46 @@ public TestMetricsLogger(IDictionary> expectedCounte public void Log(ICounterPayload payload) { - string key = CreateKey(payload); - - _metrics[key] = payload; + bool isValuePayload = payload.EventType switch + { + EventType.Gauge => true, + EventType.UpDownCounter => true, + EventType.Histogram => true, + EventType.Rate => true, + _ => false + }; + if(!isValuePayload) + { + return; + } - // Complete the task source if the last expected key was removed. - if (_expectedCounters.Remove(key) && _expectedCounters.Count == 0) + ExpectedCounter expectedCounter = _expectedCounters.Find(c => c.MatchesCounterMetadata(payload.CounterMetadata)); + if(expectedCounter != null) { - _foundExpectedCountersSource.TrySetResult(null); + _expectedCounters.Remove(expectedCounter); + _metrics.Add(expectedCounter, payload); + // Complete the task source if the last expected key was removed. + if (_expectedCounters.Count == 0) + { + _foundExpectedCountersSource.TrySetResult(null); + } } } public Task PipelineStarted(CancellationToken token) => Task.CompletedTask; public Task PipelineStopped(CancellationToken token) => Task.CompletedTask; - - private static string CreateKey(ICounterPayload payload) - { - return CreateKey(payload.CounterMetadata.ProviderName, payload.CounterMetadata.CounterName); - } - - private static string CreateKey(string providerName, string counterName) - { - return $"{providerName}_{counterName}"; - } } [SkippableTheory, MemberData(nameof(Configurations))] public async Task TestCounterEventPipeline(TestConfiguration config) { - if (config.RuntimeFrameworkVersionMajor > 8) - { - throw new SkipTestException("Not supported on .NET 9.0 and greater"); - } string[] expectedCounters = new[] { "cpu-usage", "working-set" }; string expectedProvider = "System.Runtime"; - IDictionary> expectedMap = new Dictionary>(); - expectedMap.Add(expectedProvider, expectedCounters); - TaskCompletionSource foundExpectedCountersSource = new(TaskCreationOptions.RunContinuationsAsynchronously); - TestMetricsLogger logger = new(expectedMap, foundExpectedCountersSource); + TestMetricsLogger logger = new(expectedCounters.Select(name => new ExpectedCounter(expectedProvider, name)), foundExpectedCountersSource); await using (TestRunner testRunner = await PipelineTestUtilities.StartProcess(config, "CounterRemoteTest", _output)) { @@ -114,7 +127,8 @@ public async Task TestCounterEventPipeline(TestConfiguration config) new EventPipeCounterGroup { ProviderName = expectedProvider, - CounterNames = expectedCounters + CounterNames = expectedCounters, + Type = CounterGroupType.EventCounter } }, CounterIntervalSeconds = 1 @@ -133,5 +147,53 @@ await PipelineTestUtilities.ExecutePipelineWithTracee( Assert.Equal(expectedCounters, actualMetrics); Assert.True(logger.Metrics.All(m => string.Equals(m.CounterMetadata.ProviderName, expectedProvider))); } + + [SkippableTheory, MemberData(nameof(Configurations))] + public async Task TestDuplicateNameMetrics(TestConfiguration config) + { + if(config.RuntimeFrameworkVersionMajor < 9) + { + throw new SkipTestException("MetricsEventSource only supports instrument IDs starting in .NET 9.0."); + } + string providerName = "AmbiguousNameMeter"; + string counterName = "AmbiguousNameCounter"; + ExpectedCounter[] expectedCounters = + [ + new ExpectedCounter(providerName, counterName, "MeterTag=one","InstrumentTag=A"), + new ExpectedCounter(providerName, counterName, "MeterTag=one","InstrumentTag=B"), + new ExpectedCounter(providerName, counterName, "MeterTag=two","InstrumentTag=A"), + new ExpectedCounter(providerName, counterName, "MeterTag=two","InstrumentTag=B"), + ]; + TaskCompletionSource foundExpectedCountersSource = new(TaskCreationOptions.RunContinuationsAsynchronously); + TestMetricsLogger logger = new(expectedCounters, foundExpectedCountersSource); + + await using (TestRunner testRunner = await PipelineTestUtilities.StartProcess(config, "DuplicateNameMetrics", _output)) + { + DiagnosticsClient client = new(testRunner.Pid); + + await using MetricsPipeline pipeline = new(client, new MetricsPipelineSettings + { + Duration = Timeout.InfiniteTimeSpan, + CounterGroups = new[] + { + new EventPipeCounterGroup + { + ProviderName = providerName, + CounterNames = [counterName] + } + }, + CounterIntervalSeconds = 1, + MaxTimeSeries = 1000 + }, new[] { logger }); + + await PipelineTestUtilities.ExecutePipelineWithTracee( + pipeline, + testRunner, + foundExpectedCountersSource); + } + + // confirm that all four tag combinations published a value + Assert.Equal(4, logger.Metrics.Count()); + } } }