diff --git a/Directory.Packages.props b/Directory.Packages.props index 574007a020..6253a1e046 100644 --- a/Directory.Packages.props +++ b/Directory.Packages.props @@ -101,6 +101,7 @@ + diff --git a/src/Adapter/MSTest.TestAdapter/InternalAPI/InternalAPI.Unshipped.txt b/src/Adapter/MSTest.TestAdapter/InternalAPI/InternalAPI.Unshipped.txt index 4d171bbb50..8ebfbb459a 100644 --- a/src/Adapter/MSTest.TestAdapter/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Adapter/MSTest.TestAdapter/InternalAPI/InternalAPI.Unshipped.txt @@ -60,3 +60,10 @@ static Microsoft.Testing.Extensions.RunSettingsProviderHelper.TryLoadRunSettings static Microsoft.VisualStudio.TestTools.UnitTesting.MSTestTestNodeConverter.ToEmptyResultTestNode(Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.UnitTestElement! element, bool isTrxEnabled) -> Microsoft.Testing.Platform.Extensions.Messages.TestNode! static readonly Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.AdapterTestProperties.DependenciesProperty -> Microsoft.VisualStudio.TestPlatform.ObjectModel.TestProperty! static readonly Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.AdapterTestProperties.ResourceLocksProperty -> Microsoft.VisualStudio.TestPlatform.ObjectModel.TestProperty! +Microsoft.VisualStudio.TestTools.UnitTesting.MSTestPlatformActivity +Microsoft.VisualStudio.TestTools.UnitTesting.MSTestPlatformActivity.Dispose() -> void +Microsoft.VisualStudio.TestTools.UnitTesting.MSTestPlatformActivity.MSTestPlatformActivity(Microsoft.Testing.Platform.Telemetry.IPlatformActivity! activity) -> void +Microsoft.VisualStudio.TestTools.UnitTesting.MSTestPlatformActivity.RecordException(System.Exception! exception) -> void +Microsoft.VisualStudio.TestTools.UnitTesting.MSTestPlatformActivity.SetFailed(string? description) -> void +Microsoft.VisualStudio.TestTools.UnitTesting.MSTestPlatformActivity.SetTag(string! key, object? value) -> void +static Microsoft.VisualStudio.TestTools.UnitTesting.MSTestPlatformActivity.TryEnable(System.IServiceProvider! serviceProvider) -> void diff --git a/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestPlatformActivity.cs b/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestPlatformActivity.cs new file mode 100644 index 0000000000..1684f25d0e --- /dev/null +++ b/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestPlatformActivity.cs @@ -0,0 +1,51 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +#if !WINDOWS_UWP +using Microsoft.Testing.Platform.Telemetry; +using Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter; + +namespace Microsoft.VisualStudio.TestTools.UnitTesting; + +/// +/// Bridges the engine's dependency-free seam onto the platform's OpenTelemetry +/// service, so MSTest fixture and test-method spans nest under the platform's test-case spans. +/// +[SuppressMessage("ApiDesign", "RS0030:Do not use banned APIs", Justification = "We can use MTP from this folder")] +internal sealed class MSTestPlatformActivity(IPlatformActivity activity) : IMSTestActivity +{ + public void SetTag(string key, object? value) + => activity.SetTag(key, value); + + public void RecordException(Exception exception) + => activity.RecordException(exception); + + public void SetFailed(string? description) + => activity.SetStatus(PlatformActivityStatusCode.Error, description); + + public void Dispose() + => activity.Dispose(); + + /// + /// Installs the tracing factory on when the platform has an OpenTelemetry + /// service registered. Does nothing (leaving MSTest tracing disabled and free) otherwise. + /// + internal static void TryEnable(IServiceProvider serviceProvider) + { + if (serviceProvider.GetService(typeof(IPlatformOpenTelemetryService)) is not IPlatformOpenTelemetryService otelService) + { + MSTestInstrumentation.SetActivityFactory(null); + return; + } + + MSTestInstrumentation.SetActivityFactory((name, tags) + // A non-ambient span is required, not an optimization - see the remarks on MSTestInstrumentation. + // Because the span is not ambient it cannot pick a parent up from the ambient context either, so it + // is parented explicitly to the same test-framework span the platform's test-case spans use, which + // keeps everything in one trace. + => otelService.StartNonAmbientActivity(name, tags, otelService.TestFrameworkActivity?.Id) is { } platformActivity + ? new MSTestPlatformActivity(platformActivity) + : null); + } +} +#endif diff --git a/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestTestFramework.cs b/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestTestFramework.cs index 6f1169b68c..7633bcf5b2 100644 --- a/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestTestFramework.cs +++ b/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestTestFramework.cs @@ -55,6 +55,10 @@ public MSTestTestFramework(MSTestExtension extension, Func _configuration = new(serviceProvider.GetConfiguration()); _loggerFactory = serviceProvider.GetRequiredService(); PlatformServiceProvider.Instance.AdapterTraceLogger = new MTPTraceLogger(_loggerFactory.CreateLogger("mstest-trace")); + + // Let the engine emit fixture/test-method spans that nest under the platform's test-case spans. This is a + // no-op unless the OpenTelemetry extension is registered. + MSTestPlatformActivity.TryEnable(serviceProvider); } public string Uid => _extension.Uid; diff --git a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestAssemblyInfo.cs b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestAssemblyInfo.cs index a66542a7df..00329abe31 100644 --- a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestAssemblyInfo.cs +++ b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestAssemblyInfo.cs @@ -186,6 +186,16 @@ public async Task RunAssemblyInitializeAsync(TestContext testContext // Perform a check again. if (!IsAssemblyInitializeExecuted) { + // Assembly initialize can dominate the wall-clock time of a run (spinning up a database, + // a browser, ...). Giving it its own span is what lets you tell "the test is slow" apart + // from "the assembly fixture is slow". + using IMSTestActivity? activity = MSTestInstrumentation.IsEnabled + ? MSTestInstrumentation.StartFixtureActivity( + MSTestInstrumentation.ActivityNames.AssemblyInitialize, + "assembly_initialize", + AssemblyInitializeMethod.DeclaringType?.FullName, + Assembly.GetName().Name) + : null; try { AssemblyInitializationException = await FixtureMethodRunner.RunWithTimeoutAndCancellationAsync( @@ -223,6 +233,13 @@ public async Task RunAssemblyInitializeAsync(TestContext testContext } finally { + // RunWithTimeoutAndCancellationAsync *returns* (rather than throws) the failure for the + // timeout and cancellation paths, so the catch above is not enough to mark the span failed. + if (AssemblyInitializationException is not null) + { + activity?.RecordException(AssemblyInitializationException); + } + IsAssemblyInitializeExecuted = true; } } @@ -273,6 +290,13 @@ private static TestFailedException GetTestFailedExceptionFromAssemblyInitializeE try { await _assemblyInfoExecuteSyncSemaphore.WaitAsync().ConfigureAwait(false); + using IMSTestActivity? activity = MSTestInstrumentation.IsEnabled + ? MSTestInstrumentation.StartFixtureActivity( + MSTestInstrumentation.ActivityNames.AssemblyCleanup, + "assembly_cleanup", + AssemblyCleanupMethod.DeclaringType?.FullName, + Assembly.GetName().Name) + : null; AssemblyCleanupException = await FixtureMethodRunner.RunWithTimeoutAndCancellationAsync( () => AssemblyCleanupMethod.InvokeAsFixtureMethodAsync( testContext, @@ -283,6 +307,13 @@ private static TestFailedException GetTestFailedExceptionFromAssemblyInitializeE ExecutionContext, Resource.AssemblyCleanupWasCancelled, Resource.AssemblyCleanupTimedOut).ConfigureAwait(false); + + // RunWithTimeoutAndCancellationAsync returns (rather than throws) the failure for the timeout and + // cancellation paths, so record it here while the span is still open. + if (AssemblyCleanupException is not null) + { + activity?.RecordException(AssemblyCleanupException); + } } catch (Exception ex) { diff --git a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestClassInfo.Cleanup.cs b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestClassInfo.Cleanup.cs index 25dcb2b9c4..f4b31b7f5c 100644 --- a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestClassInfo.Cleanup.cs +++ b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestClassInfo.Cleanup.cs @@ -197,6 +197,14 @@ internal sealed partial class TestClassInfo timeout = localTimeout; } + using IMSTestActivity? activity = MSTestInstrumentation.IsEnabled + ? MSTestInstrumentation.StartFixtureActivity( + MSTestInstrumentation.ActivityNames.ClassCleanup, + "class_cleanup", + methodInfo.DeclaringType?.FullName, + methodInfo.DeclaringType?.Assembly.GetName().Name) + : null; + TestFailedException? result = await FixtureMethodRunner.RunWithTimeoutAndCancellationAsync( () => methodInfo.InvokeAsFixtureMethodAsync( testContext, @@ -208,6 +216,11 @@ internal sealed partial class TestClassInfo Resource.ClassCleanupWasCancelled, Resource.ClassCleanupTimedOut).ConfigureAwait(false); + if (result is not null) + { + activity?.RecordException(result); + } + return result; } } diff --git a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestClassInfo.Initializer.cs b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestClassInfo.Initializer.cs index fb8581646d..16c9d5fb12 100644 --- a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestClassInfo.Initializer.cs +++ b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestClassInfo.Initializer.cs @@ -279,6 +279,16 @@ async Task DoRunAsync() timeout = localTimeout; } + // One span per class-initialize method (including inherited ones), so a slow or throwing class fixture is + // attributable in the trace instead of being folded into the first test of the class. + using IMSTestActivity? activity = MSTestInstrumentation.IsEnabled + ? MSTestInstrumentation.StartFixtureActivity( + MSTestInstrumentation.ActivityNames.ClassInitialize, + "class_initialize", + methodInfo.DeclaringType?.FullName, + methodInfo.DeclaringType?.Assembly.GetName().Name) + : null; + TestFailedException? result = await FixtureMethodRunner.RunWithTimeoutAndCancellationAsync( () => methodInfo.InvokeAsFixtureMethodAsync( testContext, @@ -290,6 +300,11 @@ async Task DoRunAsync() Resource.ClassInitializeWasCancelled, Resource.ClassInitializeTimedOut).ConfigureAwait(false); + if (result is not null) + { + activity?.RecordException(result); + } + return result; } } diff --git a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestMethodInfo.Lifecycle.cs b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestMethodInfo.Lifecycle.cs index 0889d7ad5e..1741aaae08 100644 --- a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestMethodInfo.Lifecycle.cs +++ b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestMethodInfo.Lifecycle.cs @@ -260,7 +260,15 @@ private async SynchronizationContextPreservingTask RunTestInitializeMethod timeout = localTimeout; } - return await InvokeFixtureMethodAsync( + using IMSTestActivity? activity = MSTestInstrumentation.IsEnabled + ? MSTestInstrumentation.StartFixtureActivity( + MSTestInstrumentation.ActivityNames.TestInitialize, + "test_initialize", + methodInfo.DeclaringType?.FullName, + methodInfo.DeclaringType?.Assembly.GetName().Name) + : null; + + TestFailedException? result = await InvokeFixtureMethodAsync( methodInfo, classInstance, arguments: null, @@ -268,6 +276,13 @@ private async SynchronizationContextPreservingTask RunTestInitializeMethod timeoutTokenSource, Resource.TestInitializeWasCancelled, Resource.TestInitializeTimedOut).ConfigureAwait(false); + + if (result is not null) + { + activity?.RecordException(result); + } + + return result; } private async SynchronizationContextPreservingTask InvokeGlobalInitializeMethodAsync(MethodInfo methodInfo, TimeoutInfo? timeoutInfo, CancellationTokenSource? timeoutTokenSource) @@ -288,7 +303,15 @@ private async SynchronizationContextPreservingTask RunTestInitializeMethod timeout = localTimeout; } - return await InvokeFixtureMethodAsync( + using IMSTestActivity? activity = MSTestInstrumentation.IsEnabled + ? MSTestInstrumentation.StartFixtureActivity( + MSTestInstrumentation.ActivityNames.TestCleanup, + "test_cleanup", + methodInfo.DeclaringType?.FullName, + methodInfo.DeclaringType?.Assembly.GetName().Name) + : null; + + TestFailedException? result = await InvokeFixtureMethodAsync( methodInfo, classInstance, arguments: null, @@ -296,6 +319,13 @@ private async SynchronizationContextPreservingTask RunTestInitializeMethod timeoutTokenSource, Resource.TestCleanupWasCancelled, Resource.TestCleanupTimedOut).ConfigureAwait(false); + + if (result is not null) + { + activity?.RecordException(result); + } + + return result; } private async SynchronizationContextPreservingTask InvokeGlobalCleanupMethodAsync(MethodInfo methodInfo, TimeoutInfo? timeoutInfo, CancellationTokenSource? timeoutTokenSource) diff --git a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestMethodRunner.cs b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestMethodRunner.cs index aba0af1dab..8ede15e79e 100644 --- a/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestMethodRunner.cs +++ b/src/Adapter/MSTestAdapter.PlatformServices/Execution/TestMethodRunner.cs @@ -19,6 +19,14 @@ namespace Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution; [StackTraceHidden] internal sealed partial class TestMethodRunner { + /// + /// The aggregate outcome names reported on the span, matching the OpenTelemetry + /// test.case.result.status enum. + /// + private const string FailedOutcomeName = "fail"; + private const string PassedOutcomeName = "pass"; + private const string SkippedOutcomeName = "skipped"; + /// /// Test context which needs to be passed to the various methods of the test. /// @@ -73,7 +81,23 @@ internal async Task ExecuteAsync(string? initializationLogs, strin { _testContext.Context.TestRunCount++; - TestResult[]? result = null; + // Never null once the try/catch below has run, but the compiler cannot prove that inside finally. + // Starting from an empty array keeps the null analysis honest without changing behavior on any + // reachable path (see the earlier review thread on this line). + TestResult[] result = []; + bool exceptionRecorded = false; + + // The engine-level span for the whole test method: it wraps test initialize, the body, test cleanup and any + // data-row expansion, so the platform's test-case span gains an explanation of where the time went. + using IMSTestActivity? activity = MSTestInstrumentation.IsEnabled + ? MSTestInstrumentation.StartActivity( + MSTestInstrumentation.ActivityNames.TestMethod, + [ + new(MSTestInstrumentation.Attributes.TestMethod, _test.DisplayName ?? _test.Name), + new(MSTestInstrumentation.Attributes.TestClass, _test.FullClassName), + new(MSTestInstrumentation.Attributes.TestAssembly, _test.AssemblyName), + ]) + : null; try { @@ -84,6 +108,12 @@ internal async Task ExecuteAsync(string? initializationLogs, strin // NOTE: We intentionally don't have any special casing for TestFailedException in this code path. // It's handled down by TestMethodInfo which also unwraps TargetInvocationException. // RunTestMethodAsync is not supposed to throw any exceptions. So it's always an **error** if we got an exception here. + if (activity is not null) + { + activity.RecordException(ex); + exceptionRecorded = true; + } + result = [ new TestResult @@ -96,16 +126,103 @@ internal async Task ExecuteAsync(string? initializationLogs, strin finally { // Assembly initialize and class initialize logs are pre-pended to the first result. - TestResult firstResult = result![0]; + TestResult firstResult = result[0]; firstResult.LogOutput = initializationLogs + firstResult.LogOutput; firstResult.LogError = initializationErrorLogs + firstResult.LogError; firstResult.DebugTrace = initializationTrace + firstResult.DebugTrace; firstResult.TestContextMessages = initializationTestContextMessages + firstResult.TestContextMessages; + + if (activity is not null) + { + // A folded data-driven test produces several results for a single method invocation; reporting the + // count makes that visible in the trace instead of looking like a single test. + // Note the name deliberately differs from the platform's `test.case.result.count` *metric*, which + // counts test cases per outcome across the run. + activity.SetTag("test.case.data_row.count", result.Length); + string aggregateOutcomeName = GetAggregateOutcomeName(result); + activity.SetTag("test.case.result.status", aggregateOutcomeName); + + // An ordinary assertion failure is returned in the TestResult rather than thrown, so nothing above + // recorded it. Without this the span for a failed test would stay Unset and look green in a trace. + if (!exceptionRecorded && aggregateOutcomeName == FailedOutcomeName) + { + MarkActivityFailed(activity, result); + } + } } return result; } + /// + /// Marks the span for a test whose failure was returned rather than thrown, preferring the recorded exception + /// so the trace carries the assertion message. + /// + private static void MarkActivityFailed(IMSTestActivity activity, TestResult[] results) + { + MSTestSettings settings = MSTestSettings.CurrentSettings; + foreach (TestResult testResult in results) + { + if (MapOutcomeName(testResult.Outcome, settings) != FailedOutcomeName) + { + continue; + } + + if (testResult.TestFailureException is { } failureException) + { + activity.RecordException(failureException); + } + else + { + activity.SetFailed(testResult.Outcome.ToString()); + } + + return; + } + } + + private static string GetAggregateOutcomeName(TestResult[] results) + { + bool anyFailed = false; + bool allSkipped = true; + MSTestSettings settings = MSTestSettings.CurrentSettings; + foreach (TestResult testResult in results) + { + switch (MapOutcomeName(testResult.Outcome, settings)) + { + case FailedOutcomeName: + anyFailed = true; + allSkipped = false; + break; + case SkippedOutcomeName: + break; + default: + allSkipped = false; + break; + } + } + + return anyFailed ? FailedOutcomeName : allSkipped ? SkippedOutcomeName : PassedOutcomeName; + } + + /// + /// Maps a single outcome onto the span's result status using the same rules the adapter applies when it + /// reports the result, so a span never disagrees with the reported outcome. + /// + /// + /// Mirrors UnitTestOutcomeHelper.ToTestOutcome, which lives in the adapter layer above and cannot be + /// referenced from here: this assembly is deliberately free of the VSTest object model. Keep the two in sync. + /// + private static string MapOutcomeName(UnitTestOutcome outcome, MSTestSettings settings) + => outcome switch + { + UnitTestOutcome.Passed => PassedOutcomeName, + UnitTestOutcome.Failed or UnitTestOutcome.Error or UnitTestOutcome.Timeout or UnitTestOutcome.Aborted or UnitTestOutcome.Unknown => FailedOutcomeName, + UnitTestOutcome.NotRunnable => settings.MapNotRunnableToFailed ? FailedOutcomeName : SkippedOutcomeName, + UnitTestOutcome.Inconclusive => settings.MapInconclusiveToFailed ? FailedOutcomeName : SkippedOutcomeName, + _ => SkippedOutcomeName, + }; + /// /// Runs the test method. /// diff --git a/src/Adapter/MSTestAdapter.PlatformServices/InternalAPI/InternalAPI.Unshipped.txt b/src/Adapter/MSTestAdapter.PlatformServices/InternalAPI/InternalAPI.Unshipped.txt index f1cbbca2d5..e9f456399b 100644 --- a/src/Adapter/MSTestAdapter.PlatformServices/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Adapter/MSTestAdapter.PlatformServices/InternalAPI/InternalAPI.Unshipped.txt @@ -12,6 +12,21 @@ *REMOVED*Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.TestContextImplementation.WriteTrace(char value) -> void *REMOVED*Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.TestContextImplementation.WriteTrace(string? value) -> void #nullable enable +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames.AssemblyCleanup = "MSTest.AssemblyCleanup" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames.AssemblyInitialize = "MSTest.AssemblyInitialize" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames.ClassCleanup = "MSTest.ClassCleanup" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames.ClassInitialize = "MSTest.ClassInitialize" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames.Discovery = "MSTest.Discovery" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames.TestCleanup = "MSTest.TestCleanup" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames.TestInitialize = "MSTest.TestInitialize" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames.TestMethod = "MSTest.TestMethod" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.Attributes.DataRowIndex = "test.case.data_row.index" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.Attributes.FixtureKind = "test.fixture.kind" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.Attributes.RetryAttempt = "test.case.retry.attempt" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.Attributes.TestAssembly = "test.assembly.name" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.Attributes.TestClass = "test.suite.name" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.Attributes.TestMethod = "test.case.name" -> string! +const Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.Attributes.TimeoutMilliseconds = "test.case.timeout" -> string! Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.AsyncReaderWriterLock Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.AsyncReaderWriterLock.AcquireReaderAsync(System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task! Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.AsyncReaderWriterLock.AcquireWriterAsync(System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task! @@ -53,6 +68,13 @@ Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.UnitTestRunner. Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.UnitTestRunner.RunSingleTestAsync(Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.UnitTestElement! unitTestElement, System.Collections.Generic.IDictionary! testContextProperties, System.Collections.Generic.IDictionary! lifecycleContextProperties, Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.Interface.IAdapterMessageLogger! messageLogger) -> System.Threading.Tasks.Task! Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Helpers.FixtureKind.GlobalTestCleanup = 7 -> Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Helpers.FixtureKind Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Helpers.FixtureKind.GlobalTestInitialize = 6 -> Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Helpers.FixtureKind +Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.IMSTestActivity +Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.IMSTestActivity.RecordException(System.Exception! exception) -> void +Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.IMSTestActivity.SetTag(string! key, object? value) -> void +Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.IMSTestActivity.SetFailed(string? description) -> void +Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation +Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.ActivityNames +Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.Attributes Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestSettings.DeclaredDependencies.get -> Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.TestDependencyDeclaration![]? Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestSettings.GlobalTestCleanupTimeout.get -> int Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestSettings.GlobalTestInitializeTimeout.get -> int @@ -96,6 +118,10 @@ static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.TestMeth static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.UnitTestRunner.CreateLiveOutputWriter(System.IO.Stream! standardOutput, System.Text.Encoding! encoding) -> System.IO.TextWriter! static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Helpers.RuntimeContext.IsMultiThreaded.get -> bool static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestDiscovererHelpers.GetSettingsExceptionMessage(Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.AdapterSettingsException! ex) -> string! +static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.IsEnabled.get -> bool +static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.SetActivityFactory(System.Func>?, Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.IMSTestActivity?>? activityFactory) -> void +static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.StartActivity(string! name, System.Collections.Generic.IEnumerable>? tags = null) -> Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.IMSTestActivity? +static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestInstrumentation.StartFixtureActivity(string! name, string! fixtureKind, string? owningType, string? assemblyName = null) -> Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.IMSTestActivity? static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.ResourceLockInfo.Decode(string! encoded) -> Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.ResourceLockInfo! static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.ResourceLockInfo.Encode(Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.ResourceLockInfo! info) -> string! static Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.TestDependencyInfo.Decode(string! encoded) -> Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.TestDependencyInfo! diff --git a/src/Adapter/MSTestAdapter.PlatformServices/Telemetry/MSTestInstrumentation.cs b/src/Adapter/MSTestAdapter.PlatformServices/Telemetry/MSTestInstrumentation.cs new file mode 100644 index 0000000000..de79ec3bac --- /dev/null +++ b/src/Adapter/MSTestAdapter.PlatformServices/Telemetry/MSTestInstrumentation.cs @@ -0,0 +1,125 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +namespace Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter; + +/// +/// A distributed-tracing span opened by the MSTest engine. +/// +internal interface IMSTestActivity : IDisposable +{ + /// + /// Adds an attribute to the span. + /// + void SetTag(string key, object? value); + + /// + /// Marks the span as failed without recording an exception event. + /// + void SetFailed(string? description); + + /// + /// Records an exception on the span and marks it as failed. + /// + void RecordException(Exception exception); +} + +/// +/// The MSTest engine's tracing seam. +/// +/// +/// +/// The engine (this assembly) is deliberately free of any Microsoft.Testing.Platform or +/// System.Diagnostics.DiagnosticSource dependency: it also runs under VSTest and under target frameworks where +/// those are not available. So instead of creating activities itself, it asks a factory that the hosting adapter +/// installs at start-up (see MSTestTestFramework, which forwards to the platform's OpenTelemetry service). +/// +/// +/// When nothing installs a factory - which is the case for VSTest, or when the OpenTelemetry extension is not +/// registered - returns and every call site degrades to a null +/// check, so the cost is a single static field read. +/// +/// +/// This is what makes the *inside* of a test observable: without it a trace shows one span per test case and no +/// explanation for a slow test, whereas with it you can see that, say, AssemblyInitialize took 8 of the 9 +/// seconds, or that a fixture and not the test body threw. +/// +/// +/// Spans created here are never ambient. MSTest captures the +/// after AssemblyInitialize, ClassInitialize and the test-level fixtures so that async-locals set there +/// flow to every subsequent test (see TestMethodRunner.ExecuteTestAsync). The ambient activity is itself an +/// async-local, so an ambient span would be captured into that context and restored for the rest of the run - +/// parenting every later span, and any activity the user's own code starts, to a span that has long since ended. +/// The factory therefore creates spans that are timed and exported but never published as the current activity, and +/// parents them explicitly instead. +/// +/// +internal static class MSTestInstrumentation +{ + /// + /// Span names, kept here so the tracing vocabulary is defined in one place. + /// + internal static class ActivityNames + { + internal const string AssemblyInitialize = "MSTest.AssemblyInitialize"; + internal const string AssemblyCleanup = "MSTest.AssemblyCleanup"; + internal const string ClassInitialize = "MSTest.ClassInitialize"; + internal const string ClassCleanup = "MSTest.ClassCleanup"; + internal const string TestInitialize = "MSTest.TestInitialize"; + internal const string TestCleanup = "MSTest.TestCleanup"; + internal const string TestMethod = "MSTest.TestMethod"; + internal const string Discovery = "MSTest.Discovery"; + } + + /// + /// Attribute names emitted by the MSTest engine, on top of the platform's test.* conventions. + /// + internal static class Attributes + { + internal const string FixtureKind = "test.fixture.kind"; + internal const string TestClass = "test.suite.name"; + internal const string TestMethod = "test.case.name"; + internal const string TestAssembly = "test.assembly.name"; + internal const string RetryAttempt = "test.case.retry.attempt"; + internal const string DataRowIndex = "test.case.data_row.index"; + internal const string TimeoutMilliseconds = "test.case.timeout"; + } + + private static volatile Func>?, IMSTestActivity?>? s_activityFactory; + + /// + /// Gets a value indicating whether a tracing factory has been installed. Call sites should use this to avoid + /// building tag payloads when tracing is off. + /// + internal static bool IsEnabled => s_activityFactory is not null; + + /// + /// Installs (or, with , removes) the factory used to create spans. + /// + internal static void SetActivityFactory(Func>?, IMSTestActivity?>? activityFactory) + => s_activityFactory = activityFactory; + + /// + /// Starts a span, or returns when tracing is not configured. + /// + internal static IMSTestActivity? StartActivity(string name, IEnumerable>? tags = null) + => s_activityFactory?.Invoke(name, tags); + + /// + /// Starts a span describing a fixture method (assembly/class/test initialize or cleanup). + /// + internal static IMSTestActivity? StartFixtureActivity(string name, string fixtureKind, string? owningType, string? assemblyName = null) + { + // Read the volatile field once: the tag array must not be built when tracing is off. + Func>?, IMSTestActivity?>? factory = s_activityFactory; + return factory is null + ? null + : factory( + name, + [ + new(Attributes.FixtureKind, fixtureKind), + new(Attributes.TestClass, owningType), + new(Attributes.TestAssembly, assemblyName), + ]); + } +} diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/ActivityWrapper.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/ActivityWrapper.cs index f7bc97c329..07a677eecf 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/ActivityWrapper.cs +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/ActivityWrapper.cs @@ -5,15 +5,92 @@ namespace Microsoft.Testing.Extensions.OpenTelemetry; -internal sealed class ActivityWrapper(Activity activity) : IPlatformActivity +internal sealed class ActivityWrapper(Activity activity, bool isAmbient = true) : IPlatformActivity { + private const string ExceptionEventName = "exception"; + private const string ExceptionTypeTag = "exception.type"; + private const string ExceptionMessageTag = "exception.message"; + private const string ExceptionStackTraceTag = "exception.stacktrace"; + public string? Id => activity.Id; + public string? TraceId => activity.IdFormat == ActivityIdFormat.W3C ? activity.TraceId.ToHexString() : null; + + public string? SpanId => activity.IdFormat == ActivityIdFormat.W3C ? activity.SpanId.ToHexString() : null; + + public bool IsRecording => activity.IsAllDataRequested; + public IPlatformActivity SetTag(string key, object? value) { activity.SetTag(key, value); return this; } - public void Dispose() => activity.Dispose(); + public IPlatformActivity SetStatus(PlatformActivityStatusCode statusCode, string? description = null) + { + activity.SetStatus( + statusCode switch + { + PlatformActivityStatusCode.Ok => ActivityStatusCode.Ok, + PlatformActivityStatusCode.Error => ActivityStatusCode.Error, + _ => ActivityStatusCode.Unset, + }, + description); + return this; + } + + public IPlatformActivity AddEvent(string name, IEnumerable>? tags = null, DateTimeOffset timestamp = default) + { + ActivityTagsCollection? tagsCollection = null; + if (tags is not null) + { + tagsCollection = []; + foreach (KeyValuePair tag in tags) + { + tagsCollection[tag.Key] = tag.Value; + } + } + + activity.AddEvent(new ActivityEvent(name, timestamp, tagsCollection)); + return this; + } + + public IPlatformActivity RecordException(Exception exception, IEnumerable>? additionalTags = null) + { + // exception.escaped is deliberately omitted: it is deprecated upstream, and a test failure is reported + // through the result attributes rather than by letting the exception escape the span. + ActivityTagsCollection tags = new() + { + [ExceptionTypeTag] = exception.GetType().FullName, + [ExceptionMessageTag] = exception.Message, + [ExceptionStackTraceTag] = exception.ToString(), + }; + + if (additionalTags is not null) + { + foreach (KeyValuePair tag in additionalTags) + { + tags[tag.Key] = tag.Value; + } + } + + activity.AddEvent(new ActivityEvent(ExceptionEventName, tags: tags)); + activity.SetStatus(ActivityStatusCode.Error, exception.Message); + return this; + } + + public void Dispose() + { + if (isAmbient) + { + activity.Dispose(); + return; + } + + // A non-ambient activity never became Activity.Current, so stopping it must not touch the ambient + // activity either. Activity.Stop() reassigns Activity.Current to its parent, so save and restore around it. + Activity? current = Activity.Current; + activity.Dispose(); + Activity.Current = current; + } } diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/CounterWrapper.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/CounterWrapper.cs index 1cde3b1643..6717ab3ff9 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/CounterWrapper.cs +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/CounterWrapper.cs @@ -17,4 +17,15 @@ public CounterWrapper(Counter counter) ?? throw new ArgumentNullException(nameof(counter)); public void Add(T delta) => _counter.Add(delta); + + public void Add(T delta, IEnumerable>? tags) + { + if (tags is null) + { + _counter.Add(delta); + return; + } + + _counter.Add(delta, MeasurementTags.ToArray(tags)); + } } diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/HistogramWrapper.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/HistogramWrapper.cs index 8c6f2062b0..59fe4a3dca 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/HistogramWrapper.cs +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/HistogramWrapper.cs @@ -18,4 +18,15 @@ public HistogramWrapper(Histogram histogram) public void Record(T value) => _histogram.Record(value); + + public void Record(T value, IEnumerable>? tags) + { + if (tags is null) + { + _histogram.Record(value); + return; + } + + _histogram.Record(value, MeasurementTags.ToArray(tags)); + } } diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/InternalAPI/InternalAPI.Unshipped.txt b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/InternalAPI/InternalAPI.Unshipped.txt index 7dc5c58110..58d983df1b 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/InternalAPI/InternalAPI.Unshipped.txt @@ -1 +1,33 @@ #nullable enable +Microsoft.Testing.Extensions.OpenTelemetry.ActivityWrapper.AddEvent(string! name, System.Collections.Generic.IEnumerable>? tags = null, System.DateTimeOffset timestamp = default(System.DateTimeOffset)) -> Microsoft.Testing.Platform.Telemetry.IPlatformActivity! +Microsoft.Testing.Extensions.OpenTelemetry.ActivityWrapper.IsRecording.get -> bool +Microsoft.Testing.Extensions.OpenTelemetry.ActivityWrapper.RecordException(System.Exception! exception, System.Collections.Generic.IEnumerable>? additionalTags = null) -> Microsoft.Testing.Platform.Telemetry.IPlatformActivity! +Microsoft.Testing.Extensions.OpenTelemetry.ActivityWrapper.SetStatus(Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode statusCode, string? description = null) -> Microsoft.Testing.Platform.Telemetry.IPlatformActivity! +Microsoft.Testing.Extensions.OpenTelemetry.ActivityWrapper.SpanId.get -> string? +Microsoft.Testing.Extensions.OpenTelemetry.ActivityWrapper.TraceId.get -> string? +Microsoft.Testing.Extensions.OpenTelemetry.CounterWrapper.Add(T delta, System.Collections.Generic.IEnumerable>? tags) -> void +Microsoft.Testing.Extensions.OpenTelemetry.HistogramWrapper.Record(T value, System.Collections.Generic.IEnumerable>? tags) -> void +Microsoft.Testing.Extensions.OpenTelemetry.MeasurementTags +Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryPlatformService.CreateObservableGauge(string! name, System.Func! observeValue, string? unit = null, string? description = null) -> void +Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryPlatformService.CreateUpDownCounter(string! name, string? unit = null, string? description = null, System.Collections.Generic.IEnumerable>? tags = null) -> Microsoft.Testing.Platform.Telemetry.IUpDownCounter! +Microsoft.Testing.Extensions.OpenTelemetry.UpDownCounterWrapper +Microsoft.Testing.Extensions.OpenTelemetry.UpDownCounterWrapper.Add(T delta, System.Collections.Generic.IEnumerable>? tags = null) -> void +Microsoft.Testing.Extensions.OpenTelemetry.UpDownCounterWrapper.UpDownCounterWrapper(System.Diagnostics.Metrics.UpDownCounter! counter) -> void +static Microsoft.Testing.Extensions.OpenTelemetry.MeasurementTags.ToArray(System.Collections.Generic.IEnumerable>? tags) -> System.Collections.Generic.KeyValuePair[]! +const Microsoft.Testing.Extensions.OpenTelemetry.TestingPlatformResourceDetector.UnknownServiceName = "unknown_test_service" -> string! +Microsoft.Testing.Extensions.OpenTelemetry.TestingPlatformResourceDetector +static Microsoft.Testing.Extensions.OpenTelemetry.TestingPlatformResourceDetector.GetResourceAttributes() -> System.Collections.Generic.IEnumerable>! +static Microsoft.Testing.Extensions.OpenTelemetry.TestingPlatformResourceDetector.GetServiceName() -> string! +static Microsoft.Testing.Extensions.OpenTelemetry.TestingPlatformResourceDetector.GetServiceVersion() -> string? +const Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryEnvironmentVariables.ExporterOtlpEndpoint = "OTEL_EXPORTER_OTLP_ENDPOINT" -> string! +const Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryEnvironmentVariables.MetricsExporter = "OTEL_METRICS_EXPORTER" -> string! +const Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryEnvironmentVariables.SdkDisabled = "OTEL_SDK_DISABLED" -> string! +const Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryEnvironmentVariables.ServiceName = "OTEL_SERVICE_NAME" -> string! +const Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryEnvironmentVariables.TracesExporter = "OTEL_TRACES_EXPORTER" -> string! +Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryEnvironmentVariables +static Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryEnvironmentVariables.IsNullOrWhiteSpace(string? value) -> bool +Microsoft.Testing.Extensions.OpenTelemetry.ActivityWrapper.ActivityWrapper(System.Diagnostics.Activity! activity, bool isAmbient = true) -> void +Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryPlatformService.HasCurrentActivity.get -> bool +Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryPlatformService.RootTraceState.get -> string? +Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryPlatformService.RootTraceState.set -> void +Microsoft.Testing.Extensions.OpenTelemetry.OpenTelemetryPlatformService.StartNonAmbientActivity(string! name, System.Collections.Generic.IEnumerable>? tags = null, string? parentId = null) -> Microsoft.Testing.Platform.Telemetry.IPlatformActivity? diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/MeasurementTags.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/MeasurementTags.cs new file mode 100644 index 0000000000..af1edf17cf --- /dev/null +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/MeasurementTags.cs @@ -0,0 +1,33 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +namespace Microsoft.Testing.Extensions.OpenTelemetry; + +/// +/// Converts the platform's dependency-free tag representation into the array shape accepted by +/// System.Diagnostics.Metrics instruments. +/// +internal static class MeasurementTags +{ + private static readonly KeyValuePair[] Empty = []; + + public static KeyValuePair[] ToArray(IEnumerable>? tags) + => tags switch + { + null => Empty, + KeyValuePair[] array => array, + ICollection> { Count: 0 } => Empty, + _ => CopyToArray(tags), + }; + + private static KeyValuePair[] CopyToArray(IEnumerable> tags) + { + List> buffer = []; + foreach (KeyValuePair tag in tags) + { + buffer.Add(tag); + } + + return buffer.ToArray(); + } +} diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/Microsoft.Testing.Extensions.OpenTelemetry.csproj b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/Microsoft.Testing.Extensions.OpenTelemetry.csproj index f219d33a8c..189b851529 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/Microsoft.Testing.Extensions.OpenTelemetry.csproj +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/Microsoft.Testing.Extensions.OpenTelemetry.csproj @@ -33,6 +33,7 @@ This package provides Open Telemetry for the platform.]]> + diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryEnvironmentVariables.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryEnvironmentVariables.cs new file mode 100644 index 0000000000..e827dd1720 --- /dev/null +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryEnvironmentVariables.cs @@ -0,0 +1,38 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +namespace Microsoft.Testing.Extensions.OpenTelemetry; + +/// +/// The subset of the standard OpenTelemetry SDK environment variables honored by the turnkey configuration. +/// +/// +/// These names are defined by the OpenTelemetry specification rather than by Microsoft.Testing.Platform, which is +/// why they live in the extension rather than in the platform's own environment variable constants. +/// +internal static class OpenTelemetryEnvironmentVariables +{ + internal const string ServiceName = "OTEL_SERVICE_NAME"; + internal const string ExporterOtlpEndpoint = "OTEL_EXPORTER_OTLP_ENDPOINT"; + internal const string TracesExporter = "OTEL_TRACES_EXPORTER"; + internal const string MetricsExporter = "OTEL_METRICS_EXPORTER"; + internal const string SdkDisabled = "OTEL_SDK_DISABLED"; + + internal static bool IsNullOrWhiteSpace([NotNullWhen(false)] string? value) + { + if (value is null) + { + return true; + } + + for (int i = 0; i < value.Length; i++) + { + if (!char.IsWhiteSpace(value[i])) + { + return false; + } + } + + return true; + } +} diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryPlatformService.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryPlatformService.cs index b18553a00c..9c64a7178e 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryPlatformService.cs +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryPlatformService.cs @@ -14,22 +14,80 @@ internal sealed class OpenTelemetryPlatformService : IPlatformOpenTelemetryServi private readonly ActivitySource _activitySource = new(ActivitySourceName, ExtensionVersion.DefaultSemVer); private readonly Meter _meter = new(MeterName, ExtensionVersion.DefaultSemVer); + private readonly List _observableInstruments = []; public IPlatformActivity? TestFrameworkActivity { get; set; } + public string? RootTraceState { get; set; } + + public bool HasCurrentActivity => Activity.Current is not null; + public IPlatformActivity? StartActivity([CallerMemberName] string name = "", IEnumerable>? tags = null, string? parentId = null, DateTimeOffset startTime = default) => _activitySource.StartActivity(name, ActivityKind.Internal, tags: tags, startTime: startTime, parentId: parentId) is Activity activity - ? new ActivityWrapper(activity) + ? new ActivityWrapper(Stamp(activity)) : null; + public IPlatformActivity? StartNonAmbientActivity(string name, IEnumerable>? tags = null, string? parentId = null) + { + Activity? ambientBeforeStart = Activity.Current; + if (_activitySource.StartActivity(name, ActivityKind.Internal, tags: tags, parentId: parentId) is not Activity activity) + { + return null; + } + + // StartActivity unconditionally publishes the new activity as Activity.Current. Undo that immediately so + // the span is timed and exported without ever leaking into an ExecutionContext captured by the code we wrap. + Activity.Current = ambientBeforeStart; + return new ActivityWrapper(Stamp(activity), isAmbient: false); + } + + /// + /// Activity only derives tracestate from an in-process parent reference, which an explicit parent id string + /// does not provide. Stamp it on so the caller's vendor sampling state survives down to the test spans. + /// + private Activity Stamp(Activity activity) + { + if (RootTraceState is not null && activity.TraceStateString is null) + { + activity.TraceStateString = RootTraceState; + } + + return activity; + } + public ICounter CreateCounter(string name, string? unit = null, string? description = null, IEnumerable>? tags = null) where T : struct => new CounterWrapper(_meter.CreateCounter(name, unit, description, tags)); + public IUpDownCounter CreateUpDownCounter(string name, string? unit = null, string? description = null, IEnumerable>? tags = null) + where T : struct + => new UpDownCounterWrapper(_meter.CreateUpDownCounter(name, unit, description, tags)); + public IHistogram CreateHistogram(string name, string? unit = null, string? description = null, IEnumerable>? tags = null) where T : struct => new HistogramWrapper(_meter.CreateHistogram(name, unit, description, tags)); + public void CreateObservableGauge(string name, Func observeValue, string? unit = null, string? description = null) + where T : struct + { + // Observable instruments are polled by the metrics pipeline for as long as the meter is alive, so we keep + // them rooted here and release them together with the meter. + ObservableGauge gauge = _meter.CreateObservableGauge(name, observeValue, unit, description); + lock (_observableInstruments) + { + _observableInstruments.Add(gauge); + } + } + public void Dispose() - => _activitySource.Dispose(); + { + // The Meter is intentionally not disposed: it is disposed of by the process exiting, and disposing it here + // would remove its instruments before the MeterProvider (registered after this service, and therefore + // disposed after it) gets a chance to flush the final measurements. + _activitySource.Dispose(); + lock (_observableInstruments) + { + _observableInstruments.Clear(); + } + } } diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryProviderExtensions.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryProviderExtensions.cs index a124e2ced0..3a93437e86 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryProviderExtensions.cs +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/OpenTelemetryProviderExtensions.cs @@ -4,8 +4,10 @@ using Microsoft.Testing.Extensions.OpenTelemetry; using Microsoft.Testing.Platform.Builder; using Microsoft.Testing.Platform.Services; +using Microsoft.Testing.Platform.Telemetry; using OpenTelemetry.Metrics; +using OpenTelemetry.Resources; using OpenTelemetry.Trace; namespace Microsoft.Testing.Extensions; @@ -67,5 +69,142 @@ public static TracerProviderBuilder AddTestingPlatformInstrumentation(this Trace /// The same instance, configured to include metrics from the Microsoft Testing /// Platform. public static MeterProviderBuilder AddTestingPlatformInstrumentation(this MeterProviderBuilder builder) - => builder.AddMeter(OpenTelemetryPlatformService.MeterName); + => builder + .AddMeter(OpenTelemetryPlatformService.MeterName) + + // Default OpenTelemetry histogram buckets top out at 10s and are tuned for HTTP latency. Test durations + // span microseconds to minutes, so without explicit buckets almost every measurement lands in the last + // bucket and percentiles become meaningless. + .AddView( + TestingPlatformSemanticConventions.Metrics.TestCaseDuration, + new ExplicitBucketHistogramConfiguration { Boundaries = [0.001, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 30, 60, 300] }) + .AddView( + TestingPlatformSemanticConventions.Metrics.TestRunDuration, + new ExplicitBucketHistogramConfiguration { Boundaries = [1, 5, 10, 30, 60, 120, 300, 600, 1800, 3600] }); + + /// + /// Adds the Microsoft Testing Platform resource attributes (test assembly, host, OS, runtime and the detected + /// CI provider, pipeline and commit) to the resource of a tracer, meter or logger provider. + /// + /// Resource attributes are attached once to every span and metric point exported by the provider, which + /// is what lets you slice a dashboard by branch, pipeline or machine without adding those values to every span. + /// The CI attributes follow the OpenTelemetry cicd.* and vcs.* conventions and are detected + /// from GitHub Actions, Azure Pipelines, GitLab CI and Jenkins environment variables. + /// The resource builder to enrich. + /// The same instance. + public static ResourceBuilder AddTestingPlatformResource(this ResourceBuilder builder) + { + _ = builder ?? throw new ArgumentNullException(nameof(builder)); + + return builder + .AddService( + serviceName: TestingPlatformResourceDetector.GetServiceName(), + serviceVersion: TestingPlatformResourceDetector.GetServiceVersion(), + autoGenerateServiceInstanceId: true) + .AddAttributes(TestingPlatformResourceDetector.GetResourceAttributes()); + } + + /// + /// Registers OpenTelemetry tracing and metrics providers configured entirely from the standard OTEL_* + /// environment variables, so a test run can be exported to an observability backend without any code change. + /// + /// + /// This is the "turnkey" counterpart of + /// : + /// it registers the Microsoft Testing Platform instrumentation, the platform resource attributes, and an exporter + /// selected from the environment. + /// + /// OTEL_SDK_DISABLED=true turns everything off. + /// OTEL_TRACES_EXPORTER / OTEL_METRICS_EXPORTER select the exporter + /// (otlp or none). When unset, otlp is used if + /// OTEL_EXPORTER_OTLP_ENDPOINT is set, otherwise nothing is exported. + /// OTEL_SERVICE_NAME overrides the service name, which otherwise defaults to the test + /// assembly name. + /// + /// The optional delegates run last, so callers can still add their own sources, instrumentation or exporters. + /// + /// The application builder to which the OpenTelemetry providers will be added. + /// An optional delegate applied after the environment-driven tracing configuration. + /// An optional delegate applied after the environment-driven metrics configuration. + public static void AddOpenTelemetryProviderFromEnvironment(this ITestApplicationBuilder builder, Action? configureTracing = null, Action? configureMetrics = null) + { + _ = builder ?? throw new ArgumentNullException(nameof(builder)); + + if (IsTrue(Environment.GetEnvironmentVariable(OpenTelemetryEnvironmentVariables.SdkDisabled))) + { + return; + } + + bool useOtlpTracing = UseOtlpExporter(OpenTelemetryEnvironmentVariables.TracesExporter); + bool useOtlpMetrics = UseOtlpExporter(OpenTelemetryEnvironmentVariables.MetricsExporter); + bool configureTracingProvider = useOtlpTracing || configureTracing is not null; + bool configureMetricsProvider = useOtlpMetrics || configureMetrics is not null; + if (!configureTracingProvider && !configureMetricsProvider) + { + return; + } + + builder.AddOpenTelemetryProvider( + tracing => + { + // Registering the source installs an ActivityListener that samples and fully tags every span, so + // when nothing will consume them we must not instrument at all - otherwise every test allocates a + // span (and copies its whole stdout/stderr into tags) just to have it dropped. + if (configureTracingProvider) + { + tracing + .AddTestingPlatformInstrumentation() + .ConfigureResource(resource => resource.AddTestingPlatformResource()); + } + + if (useOtlpTracing) + { + tracing.AddOtlpExporter(); + } + + configureTracing?.Invoke(tracing); + }, + metrics => + { + if (configureMetricsProvider) + { + metrics + .AddTestingPlatformInstrumentation() + .ConfigureResource(resource => resource.AddTestingPlatformResource()); + } + + if (useOtlpMetrics) + { + metrics.AddOtlpExporter(); + } + + configureMetrics?.Invoke(metrics); + }); + } + + private static bool UseOtlpExporter(string environmentVariableName) + { + string? configured = Environment.GetEnvironmentVariable(environmentVariableName); + + // Mirror the behavior of the OpenTelemetry auto-instrumentation: an endpoint alone is enough to opt in. + if (OpenTelemetryEnvironmentVariables.IsNullOrWhiteSpace(configured)) + { + return !OpenTelemetryEnvironmentVariables.IsNullOrWhiteSpace(Environment.GetEnvironmentVariable(OpenTelemetryEnvironmentVariables.ExporterOtlpEndpoint)); + } + + // The specification defines these variables as comma-separated lists, so 'otlp,console' must still enable + // the OTLP exporter rather than silently disabling all export. + foreach (string exporter in configured.Split(',')) + { + if (exporter.Trim().Equals("otlp", StringComparison.OrdinalIgnoreCase)) + { + return true; + } + } + + return false; + } + + private static bool IsTrue(string? value) + => value is "1" or "true" or "True" or "TRUE"; } diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/PACKAGE.md b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/PACKAGE.md index 76e18c3645..7924e8750b 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/PACKAGE.md +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/PACKAGE.md @@ -15,6 +15,11 @@ dotnet add package Microsoft.Testing.Extensions.OpenTelemetry This package extends Microsoft.Testing.Platform with: - **OpenTelemetry integration**: exposes the Microsoft Testing Platform activity source and meter (both named `Microsoft.Testing.Platform`) so test execution can be observed via the OpenTelemetry .NET SDK. +- **Semantic conventions**: where an OpenTelemetry convention exists it is used verbatim — `test.case.name`, `test.case.result.status` (upstream `pass`/`fail`), `test.suite.name`, `code.function.name`, `code.file.path`, `code.line.number`, `code.stacktrace`, `error.type`, plus an `exception` span event and an `Error` span status on failures. The pre-existing attribute and instrument names are still emitted by default so existing dashboards keep working; set `TESTINGPLATFORM_OTEL_EMIT_LEGACY_ATTRIBUTES=0` to drop them. +- **Platform extensions**: OpenTelemetry does not define any `test.*` **metrics** or test-case **span** conventions (as of semantic conventions 1.43.0), and `test.case.result.status` upstream only defines `pass` and `fail`. The instruments listed below, the additional result statuses (`skipped`, `error`, `timeout`, `cancelled`, `unknown`), `cicd.provider.name`, and the `test.case.*` attributes not listed above are therefore Microsoft.Testing.Platform extensions, deliberately placed in the namespace where an upstream definition would land. +- **Resource attributes**: `AddTestingPlatformResource()` describes *where* the run happened — test assembly, host, OS, runtime — and detects the CI provider, pipeline run, branch and commit (`cicd.*` / `vcs.*`) from GitHub Actions, Azure Pipelines, GitLab CI and Jenkins. +- **Turnkey configuration**: `AddOpenTelemetryProviderFromEnvironment()` wires instrumentation, resource and an OTLP exporter purely from the standard `OTEL_*` environment variables, so a run can be exported without writing configuration code. +- **Trace context propagation**: when the process that started the test run publishes a `TRACEPARENT` environment variable (CI runners, `dotnet test`, IDEs), the whole run nests under that trace instead of starting an orphan one. - **Lifecycle management**: ties the lifetime of a `TracerProvider` and `MeterProvider` to the test application, so they are disposed alongside the test host. - **Observability**: lets you route test execution data, via your own OpenTelemetry exporter configuration, into observability backends (e.g. Jaeger, Prometheus, Grafana). - **Standards-based**: leverages the OpenTelemetry .NET SDK so that data is sent only to the telemetry exporters and endpoints that you configure. @@ -25,6 +30,35 @@ This package extends Microsoft.Testing.Platform with: > - register at least one exporter (for example `AddOtlpExporter`, `AddConsoleExporter`, or a vendor-specific exporter). > > Without instrumentation, no MTP activities or metrics are collected; without an exporter, collected telemetry is not emitted anywhere. +> +> Use `AddOpenTelemetryProviderFromEnvironment()` instead if you want all of that configured for you from the standard `OTEL_*` variables. It only installs the instrumentation when an exporter is actually configured (via `OTEL_TRACES_EXPORTER` / `OTEL_METRICS_EXPORTER` / `OTEL_EXPORTER_OTLP_ENDPOINT`) or when you pass a configuration delegate, so leaving it in `Program.cs` unconditionally costs nothing on machines that do not opt in. + +## Emitted metrics + +| Instrument | Type | Unit | Description | +| --- | --- | --- | --- | +| `test.case.duration` | Histogram | `s` | Duration of a single test case, dimensioned by `test.case.result.status` and `test.suite.name`. | +| `test.case.result.count` | Counter | `{test}` | Number of test cases, dimensioned by `test.case.result.status` and `test.suite.name`. | +| `test.case.active` | UpDownCounter | `{test}` | Test cases currently running. | +| `test.run.duration` | Histogram | `s` | Duration of the whole run, dimensioned by `test.run.result.status` and `test.run.exit_code`. | +| `test.case.retry.count` | Counter | `{test}` | Test cases scheduled for a retry attempt (requires `Microsoft.Testing.Extensions.Retry`). | + +Metric dimensions are deliberately kept low-cardinality. Unbounded values such as the per-run test counts are set on +the root span (`test.run.total`, `test.run.failed`, `test.run.skipped`) rather than used as metric dimensions. +Span durations are reported in milliseconds under `test.case.duration_ms`, distinct from the seconds-valued +`test.case.duration` metric. + +The legacy `tests.discovered` / `tests.started` / `tests.completed` / `tests.passed` / `tests.failed` / `tests.skipped` / `tests.unknown` counters and the `tests.duration` histogram (in milliseconds) are still emitted unless legacy attributes are disabled. + +## Configuration + +| Environment variable | Default | Meaning | +| --- | --- | --- | +| `TRACEPARENT` / `TRACESTATE` | unset | W3C trace context to nest the run under. | +| `TESTINGPLATFORM_OTEL_CAPTURE_TEST_OUTPUT` | `1` | Attach captured stdout/stderr to test spans. Set to `0` when the output can contain secrets. | +| `TESTINGPLATFORM_OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT` | `8192` | Maximum characters kept for a single string attribute. Applies to both the semantic-convention and the legacy attribute names. | +| `TESTINGPLATFORM_OTEL_EMIT_LEGACY_ATTRIBUTES` | `1` | Emit the pre-semantic-convention attribute and instrument names alongside the new ones. | +| `OTEL_SDK_DISABLED`, `OTEL_SERVICE_NAME`, `OTEL_EXPORTER_OTLP_ENDPOINT`, `OTEL_TRACES_EXPORTER`, `OTEL_METRICS_EXPORTER` | unset | Standard OpenTelemetry variables honored by `AddOpenTelemetryProviderFromEnvironment`. | ## Documentation diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/PublicAPI/PublicAPI.Unshipped.txt b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/PublicAPI/PublicAPI.Unshipped.txt index 7dc5c58110..873ef5d083 100644 --- a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/PublicAPI/PublicAPI.Unshipped.txt +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/PublicAPI/PublicAPI.Unshipped.txt @@ -1 +1,3 @@ #nullable enable +[TPEXP]static Microsoft.Testing.Extensions.OpenTelemetryProviderExtensions.AddOpenTelemetryProviderFromEnvironment(this Microsoft.Testing.Platform.Builder.ITestApplicationBuilder! builder, System.Action? configureTracing = null, System.Action? configureMetrics = null) -> void +[TPEXP]static Microsoft.Testing.Extensions.OpenTelemetryProviderExtensions.AddTestingPlatformResource(this OpenTelemetry.Resources.ResourceBuilder! builder) -> OpenTelemetry.Resources.ResourceBuilder! diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/TestingPlatformResourceDetector.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/TestingPlatformResourceDetector.cs new file mode 100644 index 0000000000..00c8171fab --- /dev/null +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/TestingPlatformResourceDetector.cs @@ -0,0 +1,232 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +namespace Microsoft.Testing.Extensions.OpenTelemetry; + +/// +/// Builds the OpenTelemetry Resource attributes that describe *where* a test run happened. +/// +/// +/// Traces and metrics coming out of a test run are only actionable when you can tell one run apart from another: +/// which assembly, which machine, which CI pipeline, which branch and commit. Those belong on the resource rather +/// than on each span, because they are constant for the whole process and backends index them. +/// +internal static class TestingPlatformResourceDetector +{ + internal const string UnknownServiceName = "unknown_test_service"; + + public static IEnumerable> GetResourceAttributes() + { + foreach (KeyValuePair attribute in GetProcessAttributes()) + { + yield return attribute; + } + + foreach (KeyValuePair attribute in GetCiAttributes()) + { + yield return attribute; + } + } + + public static string GetServiceName() + { + string? fromEnvironment = Environment.GetEnvironmentVariable(OpenTelemetryEnvironmentVariables.ServiceName); + return !OpenTelemetryEnvironmentVariables.IsNullOrWhiteSpace(fromEnvironment) + ? fromEnvironment + : Assembly.GetEntryAssembly()?.GetName().Name ?? UnknownServiceName; + } + + public static string? GetServiceVersion() + => Assembly.GetEntryAssembly()?.GetCustomAttribute()?.InformationalVersion + ?? Assembly.GetEntryAssembly()?.GetName().Version?.ToString(); + + private static IEnumerable> GetProcessAttributes() + { + yield return new("host.name", Environment.MachineName); + yield return new("host.arch", GetHostArchitecture()); + + // os.type has no defined catch-all value upstream, so an unrecognised platform omits the attribute rather + // than inventing one. + if (GetOsType() is { } osType) + { + yield return new("os.type", osType); + } + + yield return new("os.description", RuntimeInformation.OSDescription); + yield return new("process.pid", GetCurrentProcessId()); + yield return new("process.runtime.name", ".NET"); + yield return new("process.runtime.description", RuntimeInformation.FrameworkDescription); + + if (Assembly.GetEntryAssembly()?.GetName().Name is { } entryAssemblyName) + { + yield return new("test.assembly.name", entryAssemblyName); + } + } + + private static int GetCurrentProcessId() + { +#if NET + return Environment.ProcessId; +#else + using var process = System.Diagnostics.Process.GetCurrentProcess(); + return process.Id; +#endif + } + + private static string? GetOsType() + => RuntimeInformation.IsOSPlatform(OSPlatform.Windows) ? "windows" + : RuntimeInformation.IsOSPlatform(OSPlatform.OSX) ? "darwin" + : RuntimeInformation.IsOSPlatform(OSPlatform.Linux) ? "linux" + : null; + + /// + /// Maps onto the values allowed by the OpenTelemetry host.arch enum, which + /// does not use the .NET spellings (for example it says amd64, not x64). + /// + private static string GetHostArchitecture() + => RuntimeInformation.OSArchitecture switch + { + Architecture.X64 => "amd64", + Architecture.X86 => "x86", + Architecture.Arm => "arm32", + Architecture.Arm64 => "arm64", + _ => RuntimeInformation.OSArchitecture.ToString().ToLowerInvariant(), + }; + + /// + /// Detects the CI provider and maps its environment variables onto the OpenTelemetry cicd.* and + /// vcs.* conventions, so a failing test can be correlated with the pipeline run and commit that produced it. + /// + /// + /// cicd.pipeline.* and vcs.* are upstream-defined (release candidate). cicd.provider.name + /// is not: as of semantic conventions 1.43.0 there is no attribute identifying the CI system, so this is + /// a platform extension sitting in the namespace where an upstream definition would land. + /// + private static IEnumerable> GetCiAttributes() + { + if (IsTrue(Environment.GetEnvironmentVariable("GITHUB_ACTIONS"))) + { + yield return new("cicd.provider.name", "github_actions"); + foreach (KeyValuePair attribute in Map( + ("cicd.pipeline.name", "GITHUB_WORKFLOW"), + ("cicd.pipeline.run.id", "GITHUB_RUN_ID"), + ("cicd.pipeline.task.name", "GITHUB_JOB"), + ("vcs.ref.head.name", "GITHUB_REF_NAME"), + ("vcs.ref.head.revision", "GITHUB_SHA"), + ("vcs.repository.name", "GITHUB_REPOSITORY"))) + { + yield return attribute; + } + + yield break; + } + + if (IsTrue(Environment.GetEnvironmentVariable("TF_BUILD"))) + { + yield return new("cicd.provider.name", "azure_pipelines"); + foreach (KeyValuePair attribute in Map( + ("cicd.pipeline.name", "BUILD_DEFINITIONNAME"), + ("cicd.pipeline.run.id", "BUILD_BUILDID"), + ("cicd.pipeline.task.run.id", "SYSTEM_JOBID"), + ("vcs.ref.head.name", "BUILD_SOURCEBRANCHNAME"), + ("vcs.ref.head.revision", "BUILD_SOURCEVERSION"), + ("vcs.repository.url.full", "BUILD_REPOSITORY_URI"))) + { + yield return attribute; + } + + yield break; + } + + if (IsTrue(Environment.GetEnvironmentVariable("GITLAB_CI"))) + { + yield return new("cicd.provider.name", "gitlab"); + foreach (KeyValuePair attribute in Map( + ("cicd.pipeline.name", "CI_PIPELINE_NAME"), + ("cicd.pipeline.run.id", "CI_PIPELINE_ID"), + ("cicd.pipeline.task.run.id", "CI_JOB_ID"), + ("vcs.ref.head.name", "CI_COMMIT_REF_NAME"), + ("vcs.ref.head.revision", "CI_COMMIT_SHA"), + ("vcs.repository.url.full", "CI_REPOSITORY_URL"))) + { + yield return attribute; + } + + yield break; + } + + if (!OpenTelemetryEnvironmentVariables.IsNullOrWhiteSpace(Environment.GetEnvironmentVariable("JENKINS_URL"))) + { + yield return new("cicd.provider.name", "jenkins"); + foreach (KeyValuePair attribute in Map( + ("cicd.pipeline.name", "JOB_NAME"), + ("cicd.pipeline.run.id", "BUILD_NUMBER"), + ("vcs.ref.head.name", "GIT_BRANCH"), + ("vcs.ref.head.revision", "GIT_COMMIT"), + ("vcs.repository.url.full", "GIT_URL"))) + { + yield return attribute; + } + } + } + + private static IEnumerable> Map(params (string AttributeName, string EnvironmentVariableName)[] mappings) + { + foreach ((string attributeName, string environmentVariableName) in mappings) + { + string? value = Environment.GetEnvironmentVariable(environmentVariableName); + if (!OpenTelemetryEnvironmentVariables.IsNullOrWhiteSpace(value)) + { + if (attributeName == "vcs.repository.url.full") + { + value = RemoveUrlUserInfo(value); + } + + yield return new KeyValuePair(attributeName, value); + } + } + } + + private static string RemoveUrlUserInfo(string value) + { + int schemeSeparatorIndex = value.IndexOf("://", StringComparison.Ordinal); + if (schemeSeparatorIndex < 0) + { + return value; + } + + int authorityStartIndex = schemeSeparatorIndex + 3; + int authorityEndIndex = value.Length; + int pathIndex = value.IndexOf('/', authorityStartIndex); + if (pathIndex >= 0) + { + authorityEndIndex = pathIndex; + } + + int queryIndex = value.IndexOf('?', authorityStartIndex); + if (queryIndex >= 0 && queryIndex < authorityEndIndex) + { + authorityEndIndex = queryIndex; + } + + int fragmentIndex = value.IndexOf('#', authorityStartIndex); + if (fragmentIndex >= 0 && fragmentIndex < authorityEndIndex) + { + authorityEndIndex = fragmentIndex; + } + + int authorityLength = authorityEndIndex - authorityStartIndex; + if (authorityLength <= 0) + { + return value; + } + + int userInfoEndIndex = value.LastIndexOf('@', authorityEndIndex - 1, authorityLength); + return userInfoEndIndex < authorityStartIndex + ? value + : value.Substring(0, authorityStartIndex) + value.Substring(userInfoEndIndex + 1); + } + + private static bool IsTrue(string? value) + => value is "1" or "true" or "True" or "TRUE"; +} diff --git a/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/UpDownCounterWrapper.cs b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/UpDownCounterWrapper.cs new file mode 100644 index 0000000000..9ed7ca367d --- /dev/null +++ b/src/Platform/Microsoft.Testing.Extensions.OpenTelemetry/UpDownCounterWrapper.cs @@ -0,0 +1,29 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using System.Diagnostics.Metrics; + +using Microsoft.Testing.Platform.Telemetry; + +namespace Microsoft.Testing.Extensions.OpenTelemetry; + +internal sealed class UpDownCounterWrapper : IUpDownCounter + where T : struct +{ + private readonly UpDownCounter _counter; + + public UpDownCounterWrapper(UpDownCounter counter) + => _counter = counter + ?? throw new ArgumentNullException(nameof(counter)); + + public void Add(T delta, IEnumerable>? tags = null) + { + if (tags is null) + { + _counter.Add(delta); + return; + } + + _counter.Add(delta, MeasurementTags.ToArray(tags)); + } +} diff --git a/src/Platform/Microsoft.Testing.Extensions.Retry/RetryOrchestrator.cs b/src/Platform/Microsoft.Testing.Extensions.Retry/RetryOrchestrator.cs index 247c50e215..25dc5b0c9e 100644 --- a/src/Platform/Microsoft.Testing.Extensions.Retry/RetryOrchestrator.cs +++ b/src/Platform/Microsoft.Testing.Extensions.Retry/RetryOrchestrator.cs @@ -10,6 +10,7 @@ using Microsoft.Testing.Platform.Logging; using Microsoft.Testing.Platform.OutputDevice; using Microsoft.Testing.Platform.Services; +using Microsoft.Testing.Platform.Telemetry; namespace Microsoft.Testing.Extensions.Policy; @@ -116,6 +117,15 @@ public async Task OrchestrateTestHostExecutionAsync(CancellationToken cance string retryRootFolder = CreateRetriesDirectory(resultDirectory); bool retryInterrupted = false; + // Retries are the single most useful thing to measure about a flaky suite, and the orchestrator is the only + // component that sees every attempt. Emitting the count here (rather than inferring it from duplicated test + // results downstream) makes "how much time do we burn on retries?" answerable from a dashboard. + IPlatformOpenTelemetryService? otelService = _serviceProvider.GetPlatformOTelService(); + ICounter? retryCounter = otelService?.CreateCounter( + TestingPlatformSemanticConventions.Metrics.TestRetryCount, + TestingPlatformSemanticConventions.Units.Count, + "Number of test cases scheduled for a retry attempt."); + // Retry summary accounting (single-assembly). The orchestrator is the only component that observes every // attempt, so it reconciles them into one headline: // retried = union of the scheduled retry sets whose following attempt reported at least one result @@ -146,6 +156,24 @@ public async Task OrchestrateTestHostExecutionAsync(CancellationToken cance { attemptCount++; + // Each attempt is a child span of the orchestrator, so a trace shows exactly how many attempts a run + // needed and how long each of them took. + using IPlatformActivity? attemptActivity = otelService?.StartActivity( + "RetryAttempt", + tags: + [ + new(TestingPlatformSemanticConventions.Attributes.TestCaseRetryAttempt, attemptCount), + new("test.retry.max_attempts", userMaxRetryCount + 1), + new("test.retry.scheduled_count", lastListOfFailedId?.Length ?? 0), + ]); + + if (attemptCount > 1) + { + retryCounter?.Add( + lastListOfFailedId?.Length ?? 0, + [new(TestingPlatformSemanticConventions.Attributes.TestCaseRetryAttempt, attemptCount)]); + } + if (attemptCount > 1 && retryDelay is { } delay) { await outputDevice.DisplayAsync( diff --git a/src/Platform/Microsoft.Testing.Platform/Helpers/EnvironmentVariableConstants.cs b/src/Platform/Microsoft.Testing.Platform/Helpers/EnvironmentVariableConstants.cs index 83eed5246e..658b90e5b0 100644 --- a/src/Platform/Microsoft.Testing.Platform/Helpers/EnvironmentVariableConstants.cs +++ b/src/Platform/Microsoft.Testing.Platform/Helpers/EnvironmentVariableConstants.cs @@ -43,6 +43,22 @@ internal static class EnvironmentVariableConstants public const string DOTNET_CLI_TELEMETRY_OPTOUT = nameof(DOTNET_CLI_TELEMETRY_OPTOUT); public const string DOTNET_NOLOGO = nameof(DOTNET_NOLOGO); + // OpenTelemetry + // W3C trace context of the process that started this test run, so the run nests under it. + public const string TRACEPARENT = nameof(TRACEPARENT); + public const string TRACESTATE = nameof(TRACESTATE); + public const string TESTINGPLATFORM_TRACEPARENT = nameof(TESTINGPLATFORM_TRACEPARENT); + public const string TESTINGPLATFORM_TRACESTATE = nameof(TESTINGPLATFORM_TRACESTATE); + + // Opts out of capturing potentially large or sensitive test output (stdout/stderr) as span attributes. + public const string TESTINGPLATFORM_OTEL_CAPTURE_TEST_OUTPUT = nameof(TESTINGPLATFORM_OTEL_CAPTURE_TEST_OUTPUT); + + // Maximum number of characters kept for a single captured output/stack trace attribute. + public const string TESTINGPLATFORM_OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT = nameof(TESTINGPLATFORM_OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT); + + // Opts out of emitting the pre-4.x attribute and instrument names alongside the semantic-convention ones. + public const string TESTINGPLATFORM_OTEL_EMIT_LEGACY_ATTRIBUTES = nameof(TESTINGPLATFORM_OTEL_EMIT_LEGACY_ATTRIBUTES); + // Debugging public const string TESTINGPLATFORM_LAUNCH_ATTACH_DEBUGGER = nameof(TESTINGPLATFORM_LAUNCH_ATTACH_DEBUGGER); public const string TESTINGPLATFORM_WAIT_ATTACH_DEBUGGER = nameof(TESTINGPLATFORM_WAIT_ATTACH_DEBUGGER); diff --git a/src/Platform/Microsoft.Testing.Platform/Helpers/ExtensionHelper.cs b/src/Platform/Microsoft.Testing.Platform/Helpers/ExtensionHelper.cs index 0c665e500b..078dd60d63 100644 --- a/src/Platform/Microsoft.Testing.Platform/Helpers/ExtensionHelper.cs +++ b/src/Platform/Microsoft.Testing.Platform/Helpers/ExtensionHelper.cs @@ -2,16 +2,43 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using Microsoft.Testing.Platform.Extensions; +using Microsoft.Testing.Platform.Telemetry; namespace Microsoft.Testing.Platform.Helpers; internal static class ExtensionHelper { + // ToOTelTags is a static extension method on IExtension with no access to the service provider, and it is + // called from several hosts and invokers. Rather than change its signature (and every call site) just to pass + // one flag, the resolved option is published here once by the host before any span is created, and only read + // afterwards. Reads happen on the host and invoker threads, hence volatile. + private static volatile bool s_emitLegacyOTelAttributes = true; + + internal static bool EmitLegacyOTelAttributes => s_emitLegacyOTelAttributes; + + /// + /// Publishes the resolved legacy-attribute option. Called once by the host at start-up, before any activity + /// exists, so that honors TESTINGPLATFORM_OTEL_EMIT_LEGACY_ATTRIBUTES. + /// + internal static void ConfigureOTelLegacyAttributes(PlatformOpenTelemetryOptions options) + => s_emitLegacyOTelAttributes = options.EmitLegacyAttributes; + public static KeyValuePair[] ToOTelTags(this IExtension extension) - => [ - new("Extension.UID", extension.Uid), - new("Extension.Version", extension.Version), - new("Extension.DisplayName", extension.DisplayName), - new("Extension.Description", extension.Description), - ]; + => EmitLegacyOTelAttributes + ? [ + new(TestingPlatformSemanticConventions.Attributes.TestExtensionUid, extension.Uid), + new(TestingPlatformSemanticConventions.Attributes.TestExtensionVersion, extension.Version), + new(TestingPlatformSemanticConventions.Attributes.TestExtensionDisplayName, extension.DisplayName), + + // Legacy names, kept so existing queries and dashboards keep resolving. + new("Extension.UID", extension.Uid), + new("Extension.Version", extension.Version), + new("Extension.DisplayName", extension.DisplayName), + new("Extension.Description", extension.Description), + ] + : [ + new(TestingPlatformSemanticConventions.Attributes.TestExtensionUid, extension.Uid), + new(TestingPlatformSemanticConventions.Attributes.TestExtensionVersion, extension.Version), + new(TestingPlatformSemanticConventions.Attributes.TestExtensionDisplayName, extension.DisplayName), + ]; } diff --git a/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs b/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs index 2d17ce3f94..15f2a7ad9d 100644 --- a/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs +++ b/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs @@ -30,6 +30,16 @@ internal abstract class CommonHost(ServiceProvider serviceProvider) : IHost protected abstract bool RunTestApplicationLifeCycleCallbacks { get; } + /// + /// Gets a value indicating whether this host is the one that observes the test results, and therefore owns the + /// run-level verdict reported to telemetry. + /// + /// + /// The test host controller shares the application's TestApplicationResult but never consumes a test node + /// update: the tests run in the child test host it launches. + /// + private bool OwnsRunVerdict => this is not TestHostControllersTestHost; + public async Task RunAsync() { CancellationToken testApplicationCancellationToken = ServiceProvider.GetTestApplicationCancellationTokenSource().CancellationToken; @@ -41,8 +51,29 @@ public async Task RunAsync() try { platformOTelService = ServiceProvider.GetPlatformOTelService(); + if (platformOTelService is not null) + { + ExtensionHelper.ConfigureOTelLegacyAttributes( + PlatformOpenTelemetryOptions.FromEnvironment(ServiceProvider.GetEnvironment())); + } + string hostType = GetHostType(); - activity = platformOTelService?.StartActivity(hostType); + + // When the builder activity has already been closed (or OTel was configured late) there is no ambient + // parent, so fall back to the W3C trace context published by the process that started this run. + string? environmentParentId = platformOTelService is not null && !platformOTelService.HasCurrentActivity + ? EnvironmentTraceContext.TryGetParentId(ServiceProvider.GetEnvironment()) + : null; + + if (environmentParentId is not null && platformOTelService!.RootTraceState is null) + { + platformOTelService.RootTraceState = EnvironmentTraceContext.TryGetTraceState(ServiceProvider.GetEnvironment()); + } + + activity = platformOTelService?.StartActivity( + hostType, + tags: [new(TestingPlatformSemanticConventions.Attributes.TestHostType, hostType)], + parentId: environmentParentId); if (PushOnlyProtocol is null || PushOnlyProtocol?.IsServerMode == false) { @@ -91,6 +122,34 @@ public async Task RunAsync() } finally { + // Normalize the cancellation verdict *before* the span and the run telemetry read it. The + // post-finally adjustment below runs too late for them, so without this a cancelled run was traced + // as a generic failure and test.run.exit_code did not match the code the process exits with. + if (testApplicationCancellationToken.IsCancellationRequested) + { + exitCode = (int)ExitCode.TestSessionAborted; + } + + // Emit the run-level telemetry while the OpenTelemetry providers and the root span are still alive. + // DisposeServiceProviderAsync below tears the providers down in registration order, and they are + // registered before TestApplicationResult, so anything recorded after this point would be dropped. + // + // Only the host that actually observed the results owns the verdict. The test host controller shares + // the same TestApplicationResult instance but consumes no TestNodeUpdateMessage (the tests run in the + // child process), so reporting from there would emit a second, contradictory run record with zero + // counts and a ZeroTests exit code. + if (OwnsRunVerdict + && ServiceProvider.GetService() is TestApplicationResult testApplicationResult) + { + testApplicationResult.ReportRunTelemetry(activity, exitCode); + } + + // Record the run verdict on the root span before closing it, so a trace search on + // test.run.exit_code finds failing runs without having to open them. + activity?.SetTag(TestingPlatformSemanticConventions.Attributes.TestRunExitCode, exitCode); + activity?.SetStatus( + exitCode == (int)ExitCode.Success ? PlatformActivityStatusCode.Ok : PlatformActivityStatusCode.Error); + // Dispose the activity activity?.Dispose(); diff --git a/src/Platform/Microsoft.Testing.Platform/Hosts/TestHostBuilder.CommonServices.cs b/src/Platform/Microsoft.Testing.Platform/Hosts/TestHostBuilder.CommonServices.cs index a51eae4214..33517701bc 100644 --- a/src/Platform/Microsoft.Testing.Platform/Hosts/TestHostBuilder.CommonServices.cs +++ b/src/Platform/Microsoft.Testing.Platform/Hosts/TestHostBuilder.CommonServices.cs @@ -123,7 +123,20 @@ private async Task SetupCommonServicesAsync( if (((TelemetryManager)Telemetry).BuildOTelProvider(serviceProvider) is { } otelService) { serviceProvider.AddService(otelService); - context.BuilderActivity = serviceProvider.GetServiceInternal()?.StartActivity("TestHostBuilder", startTime: buildBuilderStart); + + // Nest the whole run under the trace context of whoever started this process (a CI pipeline step, + // `dotnet test`, an IDE, or the test host controller) so the run is not an orphan trace. + IPlatformOpenTelemetryService? platformOTelService = serviceProvider.GetServiceInternal(); + if (platformOTelService is not null) + { + // Set before creating any span so every span picks it up, including the ones created with an + // explicit parent id (which do not inherit tracestate). + platformOTelService.RootTraceState = EnvironmentTraceContext.TryGetTraceState(systemEnvironment); + context.BuilderActivity = platformOTelService.StartActivity( + TestingPlatformSemanticConventions.Activities.TestHostBuilder, + parentId: EnvironmentTraceContext.TryGetParentId(systemEnvironment), + startTime: buildBuilderStart); + } } _ = bool.TryParse(context.Configuration[PlatformConfigurationConstants.PlatformExitProcessOnUnhandledException], out bool isFileConfiguredToFailFast); diff --git a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt index d78fb0854f..51de12b251 100644 --- a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt @@ -332,3 +332,123 @@ Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporterOptions.Sho Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporterOptions.ShowRunSummary.init -> void const Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporterCommandLineOptionsProvider.ShowFlakyTestsOption = "show-flaky-tests" -> string! static Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporterCommandLineOptionsProvider.IsFlakyTestsReportingEnabled(Microsoft.Testing.Platform.CommandLine.ICommandLineOptions! commandLineOptions) -> bool +static Microsoft.Testing.Platform.Helpers.ExtensionHelper.ConfigureOTelLegacyAttributes(Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions! options) -> void +static Microsoft.Testing.Platform.Helpers.ExtensionHelper.EmitLegacyOTelAttributes.get -> bool +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Activities.TestFramework = "TestFramework" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Activities.TestHostBuilder = "TestHostBuilder" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.LegacyTestsCompleted = "tests.completed" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.LegacyTestsDiscovered = "tests.discovered" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.LegacyTestsDuration = "tests.duration" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.LegacyTestsFailed = "tests.failed" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.LegacyTestsPassed = "tests.passed" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.LegacyTestsSkipped = "tests.skipped" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.LegacyTestsStarted = "tests.started" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.LegacyTestsUnknown = "tests.unknown" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.TestCaseResultCount = "test.case.result.count" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.TestRetryCount = "test.case.retry.count" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.TestRunActiveCases = "test.case.active" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.TestRunDuration = "test.run.duration" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Units.Count = "{test}" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Units.Seconds = "s" -> string! +Microsoft.Testing.Platform.Telemetry.ICounter.Add(T delta, System.Collections.Generic.IEnumerable>? tags) -> void +Microsoft.Testing.Platform.Telemetry.IHistogram.Record(T value, System.Collections.Generic.IEnumerable>? tags) -> void +Microsoft.Testing.Platform.Telemetry.IPlatformActivity.AddEvent(string! name, System.Collections.Generic.IEnumerable>? tags = null, System.DateTimeOffset timestamp = default(System.DateTimeOffset)) -> Microsoft.Testing.Platform.Telemetry.IPlatformActivity! +Microsoft.Testing.Platform.Telemetry.IPlatformActivity.IsRecording.get -> bool +Microsoft.Testing.Platform.Telemetry.IPlatformActivity.RecordException(System.Exception! exception, System.Collections.Generic.IEnumerable>? additionalTags = null) -> Microsoft.Testing.Platform.Telemetry.IPlatformActivity! +Microsoft.Testing.Platform.Telemetry.IPlatformActivity.SetStatus(Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode statusCode, string? description = null) -> Microsoft.Testing.Platform.Telemetry.IPlatformActivity! +Microsoft.Testing.Platform.Telemetry.IPlatformActivity.SpanId.get -> string? +Microsoft.Testing.Platform.Telemetry.IPlatformActivity.TraceId.get -> string? +Microsoft.Testing.Platform.Telemetry.IPlatformOpenTelemetryService.CreateObservableGauge(string! name, System.Func! observeValue, string? unit = null, string? description = null) -> void +Microsoft.Testing.Platform.Telemetry.IPlatformOpenTelemetryService.CreateUpDownCounter(string! name, string? unit = null, string? description = null, System.Collections.Generic.IEnumerable>? tags = null) -> Microsoft.Testing.Platform.Telemetry.IUpDownCounter! +Microsoft.Testing.Platform.Telemetry.IUpDownCounter.Add(T delta, System.Collections.Generic.IEnumerable>? tags = null) -> void +Microsoft.Testing.Platform.Telemetry.OpenTelemetryResultHandler.OpenTelemetryResultHandler(Microsoft.Testing.Platform.Telemetry.IPlatformOpenTelemetryService! otelService, Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions! options) -> void +Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions.AttributeValueLengthLimit.get -> int +Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions.CaptureTestOutput.get -> bool +Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions.EmitLegacyAttributes.get -> bool +Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions.Truncate(string? value) -> string? +Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Activities +Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics +Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Units +static Microsoft.Testing.Platform.Telemetry.EnvironmentTraceContext.IsValidTraceParent(string? traceParent) -> bool +static Microsoft.Testing.Platform.Telemetry.EnvironmentTraceContext.TryGetParentId(Microsoft.Testing.Platform.Helpers.IEnvironment! environment) -> string? +static Microsoft.Testing.Platform.Telemetry.EnvironmentTraceContext.TryGetTraceState(Microsoft.Testing.Platform.Helpers.IEnvironment! environment) -> string? +static Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions.Default.get -> Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions! +static Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions.FromEnvironment(Microsoft.Testing.Platform.Helpers.IEnvironment! environment) -> Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions! +const Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions.DefaultAttributeValueLengthLimit = 8192 -> int +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.CodeFilePath = "code.file.path" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.CodeFunctionName = "code.function.name" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.CodeLineNumber = "code.line.number" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.CodeStacktrace = "code.stacktrace" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.ErrorType = "error.type" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestAssembly = "test.assembly" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestClass = "test.class" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestDuration = "test.duration.ms" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestFilePath = "test.file.path" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestId = "test.id" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestLineEnd = "test.line.end" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestLineStart = "test.line.start" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestMetadataPrefix = "test.metadataProperty." -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestMethod = "test.method" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestName = "test.name" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestNamespace = "test.namespace" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestParentId = "test.parent.id" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestResult = "test.result" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestResultExceptionMessage = "test.result.exception.message" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestResultExceptionStackTrace = "test.result.exception.stacktrace" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestResultExceptionType = "test.result.exception.type" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestResultExplanation = "test.result.explanation" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestResultTimeout = "test.result.timeout.ms" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestStderr = "test.stderr" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.LegacyTestStdout = "test.stdout" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestAssemblyName = "test.assembly.name" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestCaseId = "test.case.id" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestCaseName = "test.case.name" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestCaseParentId = "test.case.parent.id" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestCaseResultExplanation = "test.case.result.explanation" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestCaseResultStatus = "test.case.result.status" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestCaseRetryAttempt = "test.case.retry.attempt" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestCaseTimeoutMilliseconds = "test.case.timeout" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestExtensionDisplayName = "test.extension.display_name" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestExtensionUid = "test.extension.uid" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestExtensionVersion = "test.extension.version" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestFrameworkName = "test.framework.name" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestFrameworkVersion = "test.framework.version" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestHostType = "test.host.type" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestMetadataPrefix = "test.metadata." -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestOutputStderr = "test.output.stderr" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestOutputStdout = "test.output.stdout" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestRunExitCode = "test.run.exit_code" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestRunRequestType = "test.run.request_type" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestSessionId = "test.session.id" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestStepPrefix = "test.step." -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestSuiteName = "test.suite.name" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Metrics.TestCaseDuration = "test.case.duration" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus.Cancelled = "cancelled" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus.Error = "error" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus.Skipped = "skipped" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus.Timeout = "timeout" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus.Unknown = "unknown" -> string! +Microsoft.Testing.Platform.Telemetry.EnvironmentTraceContext +Microsoft.Testing.Platform.Telemetry.IUpDownCounter +Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode +Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode.Error = 2 -> Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode +Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode.Ok = 1 -> Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode +Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode.Unset = 0 -> Microsoft.Testing.Platform.Telemetry.PlatformActivityStatusCode +Microsoft.Testing.Platform.Telemetry.PlatformOpenTelemetryOptions +Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions +Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes +Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus +Microsoft.Testing.Platform.Telemetry.IPlatformOpenTelemetryService.HasCurrentActivity.get -> bool +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestCaseDurationMilliseconds = "test.case.duration_ms" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestRunFailedCount = "test.run.failed" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestRunResultStatus = "test.run.result.status" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestRunSkippedCount = "test.run.skipped" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.Attributes.TestRunTotalCount = "test.run.total" -> string! +Microsoft.Testing.Platform.Telemetry.OpenTelemetryResultHandler.NotifyRunCompleted(int totalRanTests, int failedTests, int skippedTests, int exitCode, Microsoft.Testing.Platform.Telemetry.IPlatformActivity? runActivity = null) -> void +Microsoft.Testing.Platform.Services.TestApplicationResult.ReportRunTelemetry(Microsoft.Testing.Platform.Telemetry.IPlatformActivity? runActivity, int exitCode) -> void +Microsoft.Testing.Platform.Telemetry.IPlatformOpenTelemetryService.RootTraceState.get -> string? +Microsoft.Testing.Platform.Telemetry.IPlatformOpenTelemetryService.RootTraceState.set -> void +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus.Fail = "fail" -> string! +const Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus.Pass = "pass" -> string! +static Microsoft.Testing.Platform.Telemetry.TestingPlatformSemanticConventions.TestResultStatus.ToLegacy(string! status) -> string! +Microsoft.Testing.Platform.Telemetry.IPlatformOpenTelemetryService.StartNonAmbientActivity(string! name, System.Collections.Generic.IEnumerable>? tags = null, string? parentId = null) -> Microsoft.Testing.Platform.Telemetry.IPlatformActivity? diff --git a/src/Platform/Microsoft.Testing.Platform/Requests/TestHostTestFrameworkInvoker.cs b/src/Platform/Microsoft.Testing.Platform/Requests/TestHostTestFrameworkInvoker.cs index 606e73d521..8b56d00ea6 100644 --- a/src/Platform/Microsoft.Testing.Platform/Requests/TestHostTestFrameworkInvoker.cs +++ b/src/Platform/Microsoft.Testing.Platform/Requests/TestHostTestFrameworkInvoker.cs @@ -20,6 +20,9 @@ namespace Microsoft.Testing.Platform.Requests; [SuppressMessage("Performance", "CA1852: Seal internal types", Justification = "HotReload needs to inherit and override ExecuteRequestAsync")] internal class TestHostTestFrameworkInvoker(IServiceProvider serviceProvider) : ITestFrameworkInvoker, IOutputDeviceDataProducer, IDataProducer { + private readonly PlatformOpenTelemetryOptions _openTelemetryOptions = + PlatformOpenTelemetryOptions.FromEnvironment(serviceProvider.GetEnvironment()); + protected IServiceProvider ServiceProvider { get; } = serviceProvider; public string Uid => nameof(TestHostTestFrameworkInvoker); @@ -49,6 +52,8 @@ internal class TestHostTestFrameworkInvoker(IServiceProvider serviceProvider) : public async Task ExecuteAsync(ITestFramework testFramework, ClientInfo client, CancellationToken cancellationToken) { + ExtensionHelper.ConfigureOTelLegacyAttributes(_openTelemetryOptions); + ILogger logger = ServiceProvider.GetLoggerFactory().CreateLogger(); await logger.LogInformationAsync($"Test framework UID: '{testFramework.Uid}' Version: '{testFramework.Version}' DisplayName: '{testFramework.DisplayName}' Description: '{testFramework.Description}'").ConfigureAwait(false); @@ -66,14 +71,14 @@ public async Task ExecuteAsync(ITestFramework testFramework, ClientInfo client, await logger.LogDebugAsync($"Test session UID: '{sessionId.Value}'").ConfigureAwait(false); IPlatformOpenTelemetryService? otelService = ServiceProvider.GetPlatformOTelService(); - using (otelService?.StartActivity("CreateTestFrameworkSession", tags: [new("SessionUid", sessionId)])) + using (otelService?.StartActivity("CreateTestFrameworkSession", tags: GetSessionTags(sessionId))) { CreateTestSessionResult createTestSessionResult = await testFramework.CreateTestSessionAsync(new(sessionId, cancellationToken)).ConfigureAwait(false); await HandleTestSessionResultAsync(logger, "CreateTestSession", sessionId, createTestSessionResult.IsSuccess, createTestSessionResult.WarningMessage, createTestSessionResult.ErrorMessage, cancellationToken).ConfigureAwait(false); } TestExecutionRequest request; - using (otelService?.StartActivity("CreateTestRequest", tags: [new("SessionUid", sessionId)])) + using (otelService?.StartActivity("CreateTestRequest", tags: GetSessionTags(sessionId))) { ITestExecutionRequestFactory testExecutionRequestFactory = ServiceProvider.GetTestExecutionRequestFactory(); request = await testExecutionRequestFactory.CreateRequestAsync(new(sessionId), cancellationToken).ConfigureAwait(false); @@ -82,12 +87,14 @@ public async Task ExecuteAsync(ITestFramework testFramework, ClientInfo client, IMessageBus messageBus = ServiceProvider.GetMessageBus(); // Execute the test request - using (otelService?.StartActivity("ExecuteTestRequest", tags: [new("SessionUid", sessionId), new("RequestType", request.GetType().Name)])) + using (otelService?.StartActivity( + "ExecuteTestRequest", + tags: GetExecuteTestRequestTags(sessionId, request))) { await ExecuteRequestAsync(testFramework, request, messageBus, cancellationToken).ConfigureAwait(false); } - using (otelService?.StartActivity("CloseTestFrameworkSession", tags: [new("SessionUid", sessionId)])) + using (otelService?.StartActivity("CloseTestFrameworkSession", tags: GetSessionTags(sessionId))) { CloseTestSessionResult closeTestSessionResult = await testFramework.CloseTestSessionAsync(new(sessionId, cancellationToken)).ConfigureAwait(false); await HandleTestSessionResultAsync(logger, "CloseTestSession", sessionId, closeTestSessionResult.IsSuccess, closeTestSessionResult.WarningMessage, closeTestSessionResult.ErrorMessage, cancellationToken).ConfigureAwait(false); @@ -104,14 +111,48 @@ public async Task ExecuteAsync(ITestFramework testFramework, ClientInfo client, public virtual async Task ExecuteRequestAsync(ITestFramework testFramework, TestExecutionRequest request, IMessageBus messageBus, CancellationToken cancellationToken) { + ExtensionHelper.ConfigureOTelLegacyAttributes(_openTelemetryOptions); + IPlatformOpenTelemetryService? otelService = ServiceProvider.GetPlatformOTelService(); - using IPlatformActivity? testFrameworkActivity = otelService?.StartActivity("TestFramework", testFramework.ToOTelTags()); + using IPlatformActivity? testFrameworkActivity = otelService?.StartActivity( + TestingPlatformSemanticConventions.Activities.TestFramework, + [ + new(TestingPlatformSemanticConventions.Attributes.TestFrameworkName, testFramework.DisplayName), + new(TestingPlatformSemanticConventions.Attributes.TestFrameworkVersion, testFramework.Version), + .. testFramework.ToOTelTags(), + ]); otelService?.TestFrameworkActivity = testFrameworkActivity; using SemaphoreSlim requestSemaphore = new(0, 1); await testFramework.ExecuteRequestAsync(new(request, messageBus, new SemaphoreSlimRequestCompleteNotifier(requestSemaphore), cancellationToken)).ConfigureAwait(false); await requestSemaphore.WaitAsync(cancellationToken).ConfigureAwait(false); } + private KeyValuePair[] GetSessionTags(SessionUid sessionId) + => _openTelemetryOptions.EmitLegacyAttributes + ? [ + new(TestingPlatformSemanticConventions.Attributes.TestSessionId, sessionId.Value), + new("SessionUid", sessionId), + ] + : [ + new(TestingPlatformSemanticConventions.Attributes.TestSessionId, sessionId.Value), + ]; + + private KeyValuePair[] GetExecuteTestRequestTags(SessionUid sessionId, TestExecutionRequest request) + { + string requestType = request.GetType().Name; + return _openTelemetryOptions.EmitLegacyAttributes + ? [ + new(TestingPlatformSemanticConventions.Attributes.TestSessionId, sessionId.Value), + new(TestingPlatformSemanticConventions.Attributes.TestRunRequestType, requestType), + new("SessionUid", sessionId), + new("RequestType", requestType), + ] + : [ + new(TestingPlatformSemanticConventions.Attributes.TestSessionId, sessionId.Value), + new(TestingPlatformSemanticConventions.Attributes.TestRunRequestType, requestType), + ]; + } + private async Task HandleTestSessionResultAsync(ILogger logger, string phase, SessionUid sessionId, bool isSuccess, string? warningMessage, string? errorMessage, CancellationToken cancellationToken) { if (warningMessage is not null) diff --git a/src/Platform/Microsoft.Testing.Platform/Services/TestApplicationResult.cs b/src/Platform/Microsoft.Testing.Platform/Services/TestApplicationResult.cs index ea7816b034..380635b62f 100644 --- a/src/Platform/Microsoft.Testing.Platform/Services/TestApplicationResult.cs +++ b/src/Platform/Microsoft.Testing.Platform/Services/TestApplicationResult.cs @@ -50,7 +50,7 @@ public TestApplicationResult( _testCoverageResult = testCoverageResult; if (otelService is not null) { - _openTelemetryResultHandler = new OpenTelemetryResultHandler(otelService); + _openTelemetryResultHandler = new OpenTelemetryResultHandler(otelService, PlatformOpenTelemetryOptions.FromEnvironment(environment)); } _isDiscovery = _commandLineOptions.IsOptionSet(PlatformCommandLineProvider.DiscoverTestsOptionKey); @@ -210,6 +210,21 @@ public async Task SetTestAdapterTestSessionFailureAsync(string errorMessage, Can public Statistics GetStatistics() => new() { TotalRanTests = _totalRanTests, TotalFailedTests = _failedTestsCount }; + /// + /// Emits the run-level OpenTelemetry metrics and tags the root span with the run counts. + /// + /// The root span of the run, if any. + /// The exit code the host is about to return. Passed in rather than recomputed so the + /// telemetry always agrees with what the process actually exits with, including on the cancellation path. + /// + /// This deliberately does not live in : services are disposed in registration order, and the + /// OpenTelemetry provider is registered long before this one, so by the time we were disposed the + /// MeterProvider had already been shut down and the measurement was silently dropped. The host calls this + /// from its finally block instead, while the providers and the root span are still alive. + /// + internal void ReportRunTelemetry(IPlatformActivity? runActivity, int exitCode) + => _openTelemetryResultHandler?.NotifyRunCompleted(_totalRanTests, _failedTestsCount, _skippedTestsCount, exitCode, runActivity); + public void Dispose() => _openTelemetryResultHandler?.Dispose(); } diff --git a/src/Platform/Microsoft.Testing.Platform/Telemetry/EnvironmentTraceContext.cs b/src/Platform/Microsoft.Testing.Platform/Telemetry/EnvironmentTraceContext.cs new file mode 100644 index 0000000000..b0cbbe8f1d --- /dev/null +++ b/src/Platform/Microsoft.Testing.Platform/Telemetry/EnvironmentTraceContext.cs @@ -0,0 +1,117 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using Microsoft.Testing.Platform.Helpers; + +namespace Microsoft.Testing.Platform.Telemetry; + +/// +/// Reads a W3C trace context from the environment so that a test run started by an already-traced parent +/// (a CI pipeline step, dotnet test, an IDE, or a test host controller) nests under that parent instead +/// of starting an orphan trace. +/// +/// +/// The TRACEPARENT / TRACESTATE environment variables are the de-facto standard used by the +/// OpenTelemetry ecosystem (and by build systems such as Azure Pipelines and GitHub Actions runners that expose +/// them for child processes). We deliberately only read them: exporting the current context to child processes +/// is done separately by the test host controller. +/// +internal static class EnvironmentTraceContext +{ + private const int TraceParentLength = 55; + + internal static string? TryGetParentId(IEnvironment environment) + { + string? traceParent = GetFirstNonEmpty( + environment, + EnvironmentVariableConstants.TRACEPARENT, + EnvironmentVariableConstants.TESTINGPLATFORM_TRACEPARENT); + + return IsValidTraceParent(traceParent) ? traceParent : null; + } + + internal static string? TryGetTraceState(IEnvironment environment) + { + string? traceState = GetFirstNonEmpty( + environment, + EnvironmentVariableConstants.TRACESTATE, + EnvironmentVariableConstants.TESTINGPLATFORM_TRACESTATE); + + return RoslynString.IsNullOrWhiteSpace(traceState) ? null : traceState; + } + + private static string? GetFirstNonEmpty(IEnvironment environment, params string[] names) + { + foreach (string name in names) + { + string? value = environment.GetEnvironmentVariable(name); + if (!RoslynString.IsNullOrWhiteSpace(value)) + { + return value.Trim(); + } + } + + return null; + } + + /// + /// Validates the version-traceid-spanid-flags shape, so a malformed variable in the environment cannot + /// poison the whole trace. + /// + /// + /// The rules mirror what System.Diagnostics enforces internally, because when it rejects a parent id it + /// does so silently and starts a brand new trace instead - which is exactly the hard-to-debug outcome this + /// validation exists to turn into a clean "no parent". In particular the hex digits must be lowercase and the + /// version must not be ff. + /// + internal static bool IsValidTraceParent([NotNullWhen(true)] string? traceParent) + { + if (traceParent is null || traceParent.Length != TraceParentLength) + { + return false; + } + + if (traceParent[2] != '-' || traceParent[35] != '-' || traceParent[52] != '-') + { + return false; + } + + // Version 'ff' is explicitly forbidden by the W3C specification. + if (traceParent[0] == 'f' && traceParent[1] == 'f') + { + return false; + } + + for (int i = 0; i < traceParent.Length; i++) + { + if (i is 2 or 35 or 52) + { + continue; + } + + if (!IsLowerCaseHex(traceParent[i])) + { + return false; + } + } + + // An all-zero trace id or span id is invalid per the W3C specification. + return !IsAllZeros(traceParent, 3, 32) && !IsAllZeros(traceParent, 36, 16); + } + + private static bool IsAllZeros(string value, int start, int length) + { + for (int i = start; i < start + length; i++) + { + if (value[i] != '0') + { + return false; + } + } + + return true; + } + + private static bool IsLowerCaseHex(char c) + => c is (>= '0' and <= '9') or (>= 'a' and <= 'f'); +} diff --git a/src/Platform/Microsoft.Testing.Platform/Telemetry/IPlatformActivity.cs b/src/Platform/Microsoft.Testing.Platform/Telemetry/IPlatformActivity.cs index d346212907..97e1d2d2bd 100644 --- a/src/Platform/Microsoft.Testing.Platform/Telemetry/IPlatformActivity.cs +++ b/src/Platform/Microsoft.Testing.Platform/Telemetry/IPlatformActivity.cs @@ -7,5 +7,37 @@ internal interface IPlatformActivity : IDisposable { string? Id { get; } + /// + /// Gets the W3C trace id of the activity, or when unavailable. + /// + string? TraceId { get; } + + /// + /// Gets the W3C span id of the activity, or when unavailable. + /// + string? SpanId { get; } + + /// + /// Gets a value indicating whether the activity is being recorded. Callers should use this to skip building + /// expensive tag payloads (large stdout/stderr buffers, stack traces, ...) when nothing is listening. + /// + bool IsRecording { get; } + IPlatformActivity SetTag(string key, object? value); + + /// + /// Sets the status of the activity, which observability backends use to flag failures. + /// + IPlatformActivity SetStatus(PlatformActivityStatusCode statusCode, string? description = null); + + /// + /// Adds a timestamped event to the activity. + /// + IPlatformActivity AddEvent(string name, IEnumerable>? tags = null, DateTimeOffset timestamp = default); + + /// + /// Records an exception following the OpenTelemetry exception event convention and marks the activity + /// as failed. + /// + IPlatformActivity RecordException(Exception exception, IEnumerable>? additionalTags = null); } diff --git a/src/Platform/Microsoft.Testing.Platform/Telemetry/IPlatformOpenTelemetryService.cs b/src/Platform/Microsoft.Testing.Platform/Telemetry/IPlatformOpenTelemetryService.cs index bc031b56a9..69b8e5fa6d 100644 --- a/src/Platform/Microsoft.Testing.Platform/Telemetry/IPlatformOpenTelemetryService.cs +++ b/src/Platform/Microsoft.Testing.Platform/Telemetry/IPlatformOpenTelemetryService.cs @@ -16,11 +16,68 @@ internal interface IPlatformOpenTelemetryService : IDisposable { IPlatformActivity? TestFrameworkActivity { get; set; } + /// + /// Gets or sets the W3C tracestate inherited from the process that started this run. + /// + /// + /// It lives on the service rather than on a single activity because tracestate is only inherited through + /// an in-process parent reference, and most of the platform's spans are created with an explicit parent id + /// string (which leaves no parent reference). The service therefore stamps it onto every such span, so the + /// vendor sampling decision published by the caller reaches the spans that carry the test data. + /// + string? RootTraceState { get; set; } + + /// + /// Gets a value indicating whether an ambient (currently running) activity exists. Exposed as a boolean rather + /// than as the activity itself so callers cannot accidentally dispose an activity they do not own. + /// + bool HasCurrentActivity { get; } + + /// + /// Starts an activity. + /// + /// + /// Do not change this signature. Extensions ship independently of the platform, and the C# compiler + /// bakes optional-parameter defaults into the call site, so an already-published extension binary references + /// this exact signature. Adding a parameter here - even an optional one - removes that signature and makes the + /// older extension fail with a MissingMethodException at run time. Add a new method instead, and note + /// that no analyzer catches this: it only shows up in the forward-compatibility acceptance test. + /// IPlatformActivity? StartActivity([CallerMemberName] string name = "", IEnumerable>? tags = null, string? parentId = null, DateTimeOffset startTime = default); + /// + /// Starts an activity that is timed and exported but never becomes the ambient activity. + /// + /// + /// This matters for code that captures an while the span is + /// open: the ambient activity is an async-local, so it would be captured too and later restored - parenting + /// unrelated, much later work to a span that has already ended. MSTest does exactly that when it propagates + /// async-locals set by AssemblyInitialize/ClassInitialize to every subsequent test. + /// Because the span never becomes current it cannot inherit a parent from the ambient context either, so + /// pass explicitly to keep it in the right trace. + /// + /// The span name. + /// Attributes to set on the span at creation time. + /// The explicit parent of the span. + IPlatformActivity? StartNonAmbientActivity(string name, IEnumerable>? tags = null, string? parentId = null); + ICounter CreateCounter(string name, string? unit = null, string? description = null, IEnumerable>? tags = null) where T : struct; + IUpDownCounter CreateUpDownCounter(string name, string? unit = null, string? description = null, IEnumerable>? tags = null) + where T : struct; + IHistogram CreateHistogram(string name, string? unit = null, string? description = null, IEnumerable>? tags = null) where T : struct; + + /// + /// Registers an asynchronous gauge that is polled by the metrics pipeline on every collection cycle. + /// + /// The numeric type of the reported measurement. + /// The instrument name. + /// Callback invoked on every collection cycle to read the current value. + /// The UCUM unit of the measurement. + /// A human readable description of the instrument. + void CreateObservableGauge(string name, Func observeValue, string? unit = null, string? description = null) + where T : struct; } diff --git a/src/Platform/Microsoft.Testing.Platform/Telemetry/Meters.cs b/src/Platform/Microsoft.Testing.Platform/Telemetry/Meters.cs index e23e6d4874..3df631fc90 100644 --- a/src/Platform/Microsoft.Testing.Platform/Telemetry/Meters.cs +++ b/src/Platform/Microsoft.Testing.Platform/Telemetry/Meters.cs @@ -16,6 +16,28 @@ internal interface ICounter /// The value to add. The meaning of this value depends on the implementation and type parameter . void Add(T delta); + + /// + /// Adds the specified value, associating the measurement with the given attributes. + /// + /// The value to add. + /// The attributes (dimensions) of the measurement. Keep the cardinality low. + void Add(T delta, IEnumerable>? tags); +} + +/// +/// Defines a counter whose value can both increase and decrease, for example the number of tests currently running. +/// +/// The value type that the counter tracks. +internal interface IUpDownCounter + where T : struct +{ + /// + /// Adds (or subtracts, for negative deltas) the specified value. + /// + /// The value to add. + /// The attributes (dimensions) of the measurement. Keep the cardinality low. + void Add(T delta, IEnumerable>? tags = null); } /// @@ -34,4 +56,11 @@ internal interface IHistogram /// /// The value to record. May represent data to be stored, logged, or tracked depending on the implementation. void Record(T value); + + /// + /// Records the specified value, associating the measurement with the given attributes. + /// + /// The value to record. + /// The attributes (dimensions) of the measurement. Keep the cardinality low. + void Record(T value, IEnumerable>? tags); } diff --git a/src/Platform/Microsoft.Testing.Platform/Telemetry/OpenTelemetryResultHandler.cs b/src/Platform/Microsoft.Testing.Platform/Telemetry/OpenTelemetryResultHandler.cs index b33dfb6198..ac2ebfe7af 100644 --- a/src/Platform/Microsoft.Testing.Platform/Telemetry/OpenTelemetryResultHandler.cs +++ b/src/Platform/Microsoft.Testing.Platform/Telemetry/OpenTelemetryResultHandler.cs @@ -2,74 +2,146 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using Microsoft.Testing.Platform.Extensions.Messages; +using Microsoft.Testing.Platform.Helpers; namespace Microsoft.Testing.Platform.Telemetry; internal sealed class OpenTelemetryResultHandler : IDisposable { + /// + /// What Roslyn's INamespaceSymbol.ToDisplayString() returns for the global namespace. + /// + private const string RoslynGlobalNamespaceDisplayString = ""; + private const string ExceptionEventName = "exception"; + private const string ExceptionTypeTag = "exception.type"; + private const string ExceptionMessageTag = "exception.message"; + private const string ExceptionStackTraceTag = "exception.stacktrace"; + private readonly IPlatformOpenTelemetryService _otelService; - private readonly ICounter _totalDiscoveredTests; - private readonly ICounter _totalStartedTests; - private readonly ICounter _totalCompletedTests; - private readonly ICounter _totalPassedTests; - private readonly ICounter _totalFailedTests; - private readonly ICounter _totalSkippedTests; - private readonly ICounter _totalUnknownTests; - private readonly IHistogram _totalDuration; + private readonly PlatformOpenTelemetryOptions _options; + + // Semantic-convention aligned instruments. + private readonly ICounter _testCaseResultCount; + private readonly IHistogram _testCaseDuration; + private readonly IUpDownCounter _activeTestCases; + private readonly IHistogram _testRunDuration; + + // Legacy instruments, kept so existing dashboards keep working. + private readonly ICounter? _totalDiscoveredTests; + private readonly ICounter? _totalStartedTests; + private readonly ICounter? _totalCompletedTests; + private readonly ICounter? _totalPassedTests; + private readonly ICounter? _totalFailedTests; + private readonly ICounter? _totalSkippedTests; + private readonly ICounter? _totalUnknownTests; + private readonly IHistogram? _totalDuration; + + private readonly Stopwatch _runStopwatch = Stopwatch.StartNew(); + // Note: we use a queue per Uid because frameworks are allowed (but discouraged) to produce // multiple test nodes that share the same Uid (e.g. NUnit's [Values("one", "one")] or // MSTest's "folded" parameterized tests). When that happens we still want to track every // in-flight activity and pair them with results in FIFO order, instead of throwing. - private readonly Dictionary> _testActivities = []; + // The queued activity is nullable on purpose: when no tracer is listening StartActivity returns null, and we + // still need the entry so the in-flight bookkeeping (and therefore test.case.active) stays balanced. + private readonly Dictionary> _testActivities = []; + + // The notifications are normally serialised by the message bus's single-reader consumer loop. They are not on + // the cancellation path: a cancelled run skips the drain/disable step, so a consumer can still be publishing + // results while the host disposes us. Guarding the bookkeeping keeps that race from throwing a collection- + // modified exception out of the telemetry code during shutdown - telemetry must never fail a run. + // This is a local mitigation; the platform-level sequencing is tracked by + // https://github.com/microsoft/testfx/issues/10357 and this guard can be revisited once that is fixed. +#if NET9_0_OR_GREATER + private readonly Lock _syncRoot = new(); +#else + private readonly object _syncRoot = new(); +#endif private bool _disposed; + private bool _runCompletedReported; public OpenTelemetryResultHandler(IPlatformOpenTelemetryService otelService) + : this(otelService, PlatformOpenTelemetryOptions.Default) + { + } + + public OpenTelemetryResultHandler(IPlatformOpenTelemetryService otelService, PlatformOpenTelemetryOptions options) { _otelService = otelService; - _totalDiscoveredTests = otelService.CreateCounter("tests.discovered"); - _totalStartedTests = otelService.CreateCounter("tests.started"); - _totalCompletedTests = otelService.CreateCounter("tests.completed"); - _totalPassedTests = otelService.CreateCounter("tests.passed"); - _totalFailedTests = otelService.CreateCounter("tests.failed"); - _totalSkippedTests = otelService.CreateCounter("tests.skipped"); - _totalUnknownTests = otelService.CreateCounter("tests.unknown"); - _totalDuration = otelService.CreateHistogram("tests.duration"); + _options = options; + + _testCaseResultCount = otelService.CreateCounter( + TestingPlatformSemanticConventions.Metrics.TestCaseResultCount, + TestingPlatformSemanticConventions.Units.Count, + "Number of test cases, dimensioned by result status."); + _testCaseDuration = otelService.CreateHistogram( + TestingPlatformSemanticConventions.Metrics.TestCaseDuration, + TestingPlatformSemanticConventions.Units.Seconds, + "Duration of a single test case."); + _activeTestCases = otelService.CreateUpDownCounter( + TestingPlatformSemanticConventions.Metrics.TestRunActiveCases, + TestingPlatformSemanticConventions.Units.Count, + "Number of test cases currently running."); + _testRunDuration = otelService.CreateHistogram( + TestingPlatformSemanticConventions.Metrics.TestRunDuration, + TestingPlatformSemanticConventions.Units.Seconds, + "Duration of the whole test run."); + + if (options.EmitLegacyAttributes) + { + _totalDiscoveredTests = otelService.CreateCounter(TestingPlatformSemanticConventions.Metrics.LegacyTestsDiscovered); + _totalStartedTests = otelService.CreateCounter(TestingPlatformSemanticConventions.Metrics.LegacyTestsStarted); + _totalCompletedTests = otelService.CreateCounter(TestingPlatformSemanticConventions.Metrics.LegacyTestsCompleted); + _totalPassedTests = otelService.CreateCounter(TestingPlatformSemanticConventions.Metrics.LegacyTestsPassed); + _totalFailedTests = otelService.CreateCounter(TestingPlatformSemanticConventions.Metrics.LegacyTestsFailed); + _totalSkippedTests = otelService.CreateCounter(TestingPlatformSemanticConventions.Metrics.LegacyTestsSkipped); + _totalUnknownTests = otelService.CreateCounter(TestingPlatformSemanticConventions.Metrics.LegacyTestsUnknown); + _totalDuration = otelService.CreateHistogram(TestingPlatformSemanticConventions.Metrics.LegacyTestsDuration); + } } internal void NotifyDiscovered() - => _totalDiscoveredTests.Add(1); + => _totalDiscoveredTests?.Add(1); internal void NotifyPassed(TestNode testNode, TestNodeStateProperty stateProperty) { - _totalPassedTests.Add(1); + _totalPassedTests?.Add(1); HandleTestResult(testNode, stateProperty); } internal void NotifyFailed(TestNode testNode, TestNodeStateProperty stateProperty) { - _totalFailedTests.Add(1); + _totalFailedTests?.Add(1); HandleTestResult(testNode, stateProperty); } internal void NotifySkipped(TestNode testNode, TestNodeStateProperty stateProperty) { - _totalSkippedTests.Add(1); + _totalSkippedTests?.Add(1); HandleTestResult(testNode, stateProperty); } internal void NotifyInProgress(TestNode testNode, TestNodeUid? parentUid) { - _totalStartedTests.Add(1); + _totalStartedTests?.Add(1); IPlatformActivity? activity = _otelService.StartActivity( - testNode.Uid, + GetActivityName(testNode), parentId: _otelService.TestFrameworkActivity?.Id, tags: GetTestInitialInfo(testNode, parentUid)); - if (activity is not null) + lock (_syncRoot) { - if (!_testActivities.TryGetValue(testNode.Uid, out Queue? activities)) + if (_disposed) + { + // A result arrived after shutdown started; close its span rather than tracking it. + activity?.Dispose(); + return; + } + + _activeTestCases.Add(1); + if (!_testActivities.TryGetValue(testNode.Uid, out Queue? activities)) { - activities = new Queue(); + activities = new Queue(); _testActivities.Add(testNode.Uid, activities); } @@ -79,115 +151,329 @@ internal void NotifyInProgress(TestNode testNode, TestNodeUid? parentUid) internal void NotifyExecutionCompleted(TestNode testNode) { - _totalCompletedTests.Add(1); - if (!_testActivities.TryGetValue(testNode.Uid, out Queue? activities) || activities.Count == 0) + _totalCompletedTests?.Add(1); + if (!TryDequeueInFlight(testNode, out IPlatformActivity? activity)) { return; } - IPlatformActivity activity = activities.Dequeue(); - if (activities.Count == 0) + activity?.Dispose(); + } + + internal void NotifyUnknown() + => _totalUnknownTests?.Add(1); + + /// + /// Records the run-level metrics. Called once, when the run verdict is known. + /// + /// Number of tests that ran. + /// Number of tests that failed. + /// Number of tests that were skipped. + /// The process exit code the run resolved to. + /// The root span of the run, if any. The counts go here rather than on the histogram + /// because they are unbounded values: as metric dimensions they would create a new time series per distinct + /// count, while on a span they are free. + internal void NotifyRunCompleted(int totalRanTests, int failedTests, int skippedTests, int exitCode, IPlatformActivity? runActivity = null) + { + // Dispose can legitimately run more than once; recording a second data point would double count the run. + lock (_syncRoot) { - _testActivities.Remove(testNode.Uid); + if (_runCompletedReported) + { + return; + } + + _runCompletedReported = true; } - activity.Dispose(); + _runStopwatch.Stop(); + _testRunDuration.Record( + _runStopwatch.Elapsed.TotalSeconds, + [ + new(TestingPlatformSemanticConventions.Attributes.TestRunResultStatus, GetRunResultStatus(failedTests, exitCode)), + new(TestingPlatformSemanticConventions.Attributes.TestRunExitCode, exitCode), + ]); + + runActivity?.SetTag(TestingPlatformSemanticConventions.Attributes.TestRunTotalCount, totalRanTests); + runActivity?.SetTag(TestingPlatformSemanticConventions.Attributes.TestRunFailedCount, failedTests); + runActivity?.SetTag(TestingPlatformSemanticConventions.Attributes.TestRunSkippedCount, skippedTests); } - internal void NotifyUnknown() - => _totalUnknownTests.Add(1); - public void Dispose() { - if (_disposed) + List orphaned = []; + lock (_syncRoot) { - return; + if (_disposed) + { + return; + } + + _disposed = true; + + // Drain into a local list so the spans are closed outside the lock and a concurrent notification + // cannot mutate the dictionary while we walk it. + foreach (Queue activities in _testActivities.Values) + { + orphaned.AddRange(activities); + } + + if (orphaned.Count > 0) + { + _activeTestCases.Add(-orphaned.Count); + } + + _testActivities.Clear(); } - _disposed = true; - foreach (Queue activities in _testActivities.Values) + foreach (IPlatformActivity? activity in orphaned) { - foreach (IPlatformActivity activity in activities) + activity?.Dispose(); + } + } + + /// + /// Removes the oldest in-flight entry for the node and keeps test.case.active balanced. + /// + private bool TryDequeueInFlight(TestNode testNode, out IPlatformActivity? activity) + { + lock (_syncRoot) + { + activity = null; + if (!_testActivities.TryGetValue(testNode.Uid, out Queue? activities) || activities.Count == 0) { - activity.Dispose(); + return false; } - } - _testActivities.Clear(); + activity = activities.Dequeue(); + if (activities.Count == 0) + { + _testActivities.Remove(testNode.Uid); + } + + _activeTestCases.Add(-1); + return true; + } } - private static IEnumerable> GetTestInitialInfo(TestNode testNode, TestNodeUid? parentUid) + /// + /// The OpenTelemetry conventions ask for the span name to be the test case name rather than an opaque id, + /// because it is what shows up in trace waterfalls and what backends group on. + /// + private static string GetActivityName(TestNode testNode) + => RoslynString.IsNullOrWhiteSpace(testNode.DisplayName) ? testNode.Uid.Value : testNode.DisplayName; + + private static string? GetSuiteName(TestNode testNode) + => testNode.Properties.SingleOrDefault()?.TypeName; + + /// + /// Builds the value for code.function.name, which the convention defines as the fully qualified name. + /// + /// + /// + /// A type in the global namespace contributes no namespace segment, so the name must not gain a leading dot. + /// Two spellings have to be recognised, because the property is a plain string filled in by whichever test + /// framework produced the node: an empty namespace (what MSTest produces, since it derives the namespace by + /// splitting the managed type name) and Roslyn's <global namespace>, which is what + /// INamespaceSymbol.ToDisplayString() returns when the caller does not first check + /// IsGlobalNamespace. + /// + /// + /// Dropping the segment - rather than emitting Roslyn's global:: prefix - keeps the attribute + /// language-agnostic, matches the convention's own examples, and is consistent with how the rest of this + /// repository treats the global namespace (see TestClassModelBuilder, ReflectionMetadataGenerator + /// and DiscoveredTestsJsonSerializer, which all omit it). + /// + /// + private static string GetFullyQualifiedName(TestMethodIdentifierProperty identifierProperty) + => IsGlobalNamespace(identifierProperty.Namespace) + ? $"{identifierProperty.TypeName}.{identifierProperty.MethodName}" + : $"{identifierProperty.Namespace}.{identifierProperty.TypeName}.{identifierProperty.MethodName}"; + + private static bool IsGlobalNamespace(string? @namespace) + => RoslynString.IsNullOrEmpty(@namespace) + || @namespace == RoslynGlobalNamespaceDisplayString; + + private static string GetRunResultStatus(int failedTests, int exitCode) + => failedTests > 0 || exitCode != (int)ExitCode.Success + ? TestingPlatformSemanticConventions.TestResultStatus.Fail + : TestingPlatformSemanticConventions.TestResultStatus.Pass; + + private IEnumerable> GetTestInitialInfo(TestNode testNode, TestNodeUid? parentUid) { - yield return new("test.name", testNode.DisplayName); - yield return new("test.id", testNode.Uid.Value); + yield return new(TestingPlatformSemanticConventions.Attributes.TestCaseName, testNode.DisplayName); + yield return new(TestingPlatformSemanticConventions.Attributes.TestCaseId, testNode.Uid.Value); if (parentUid is not null) { - yield return new("test.parent.id", parentUid.Value); + yield return new(TestingPlatformSemanticConventions.Attributes.TestCaseParentId, parentUid.Value); + } + + if (_options.EmitLegacyAttributes) + { + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestName, testNode.DisplayName); + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestId, testNode.Uid.Value); + if (parentUid is not null) + { + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestParentId, parentUid.Value); + } } if (testNode.Properties.SingleOrDefault() is { } identifierProperty) { - yield return new("test.method", identifierProperty.MethodName); - yield return new("test.class", identifierProperty.TypeName); - yield return new("test.namespace", identifierProperty.Namespace); - yield return new("test.assembly", identifierProperty.AssemblyFullName); + // code.function.name is defined as the *fully qualified* name; there is no separate namespace + // attribute (code.namespace is deprecated upstream). + yield return new(TestingPlatformSemanticConventions.Attributes.CodeFunctionName, GetFullyQualifiedName(identifierProperty)); + yield return new(TestingPlatformSemanticConventions.Attributes.TestSuiteName, identifierProperty.TypeName); + yield return new(TestingPlatformSemanticConventions.Attributes.TestAssemblyName, identifierProperty.AssemblyFullName); + + if (_options.EmitLegacyAttributes) + { + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestMethod, identifierProperty.MethodName); + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestClass, identifierProperty.TypeName); + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestNamespace, identifierProperty.Namespace); + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestAssembly, identifierProperty.AssemblyFullName); + } } if (testNode.Properties.SingleOrDefault() is { } testLocationProperty) { - yield return new("test.file.path", testLocationProperty.FilePath); - yield return new("test.line.start", testLocationProperty.LineSpan.Start.Line); - yield return new("test.line.end", testLocationProperty.LineSpan.End.Line); + yield return new(TestingPlatformSemanticConventions.Attributes.CodeFilePath, testLocationProperty.FilePath); + yield return new(TestingPlatformSemanticConventions.Attributes.CodeLineNumber, testLocationProperty.LineSpan.Start.Line); + + if (_options.EmitLegacyAttributes) + { + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestFilePath, testLocationProperty.FilePath); + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestLineStart, testLocationProperty.LineSpan.Start.Line); + yield return new(TestingPlatformSemanticConventions.Attributes.LegacyTestLineEnd, testLocationProperty.LineSpan.End.Line); + } } foreach (TestMetadataProperty metadata in testNode.Properties.OfType()) { - yield return new KeyValuePair($"test.metadataProperty.{metadata.Key}", metadata.Value); + yield return new KeyValuePair($"{TestingPlatformSemanticConventions.Attributes.TestMetadataPrefix}{metadata.Key}", metadata.Value); + if (_options.EmitLegacyAttributes) + { + yield return new KeyValuePair($"{TestingPlatformSemanticConventions.Attributes.LegacyTestMetadataPrefix}{metadata.Key}", metadata.Value); + } } } private void HandleTestResult(TestNode testNode, TestNodeStateProperty stateProperty) { - _totalCompletedTests.Add(1); + _totalCompletedTests?.Add(1); - if (!_testActivities.TryGetValue(testNode.Uid, out Queue? activities) || activities.Count == 0) + (string result, Exception? exception, TimeSpan? timeoutTime) = stateProperty switch { - return; - } + PassedTestNodeStateProperty => (TestingPlatformSemanticConventions.TestResultStatus.Pass, null, null), + FailedTestNodeStateProperty failed => (TestingPlatformSemanticConventions.TestResultStatus.Fail, failed.Exception, null), + ErrorTestNodeStateProperty error => (TestingPlatformSemanticConventions.TestResultStatus.Error, error.Exception, null), + TimeoutTestNodeStateProperty timeout => (TestingPlatformSemanticConventions.TestResultStatus.Timeout, timeout.Exception, timeout.Timeout), +#pragma warning disable CS0618, MTP0001 // Type or member is obsolete + CancelledTestNodeStateProperty cancelled => (TestingPlatformSemanticConventions.TestResultStatus.Cancelled, cancelled.Exception, null), +#pragma warning restore CS0618, MTP0001 // Type or member is obsolete + SkippedTestNodeStateProperty => (TestingPlatformSemanticConventions.TestResultStatus.Skipped, null, null), + _ => (TestingPlatformSemanticConventions.TestResultStatus.Unknown, null, null), + }; + + KeyValuePair[] measurementTags = + [ + new(TestingPlatformSemanticConventions.Attributes.TestCaseResultStatus, result), + new(TestingPlatformSemanticConventions.Attributes.TestSuiteName, GetSuiteName(testNode)), + ]; - IPlatformActivity activity = activities.Dequeue(); - if (activities.Count == 0) + _testCaseResultCount.Add(1, measurementTags); + + if (!TryDequeueInFlight(testNode, out IPlatformActivity? activity) || activity is null) { - _testActivities.Remove(testNode.Uid); + // Either the framework never reported the test as in-progress, or nothing is listening so no span was + // created. Either way we still want the duration recorded, otherwise a framework that only publishes + // final results produces no latency data. + SetResultDetails(testNode, measurementTags, activity: null); + return; } - (string result, Exception? exception, TimeSpan? timeoutTime) = stateProperty switch + string? truncatedExplanation = _options.Truncate(stateProperty.Explanation); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.TestCaseResultStatus, result); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.TestCaseResultExplanation, truncatedExplanation); + + if (_options.EmitLegacyAttributes) { - PassedTestNodeStateProperty => ("passed", null, null), - FailedTestNodeStateProperty failed => ("failed", failed.Exception, null), - ErrorTestNodeStateProperty error => ("error", error.Exception, null), - TimeoutTestNodeStateProperty timeout => ("timeout", timeout.Exception, timeout.Timeout), -#pragma warning disable CS0618, MTP0001 // Type or member is obsolete - CancelledTestNodeStateProperty cancelled => ("cancelled", cancelled.Exception, null), -#pragma warning restore CS0618, MTP0001 // Type or member is obsolete - SkippedTestNodeStateProperty => ("skipped", null, null), - _ => ("unknown", null, null), - }; + // The legacy attribute keeps its original "passed"/"failed" spellings; the semantic-convention + // attribute uses the upstream "pass"/"fail" enum. + activity.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestResult, TestingPlatformSemanticConventions.TestResultStatus.ToLegacy(result)); + + // Truncated as well: emitting the legacy twin untruncated would defeat the size limit, since legacy + // attributes are on by default. + activity.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestResultExplanation, truncatedExplanation); + } - activity.SetTag("test.result", result); - activity.SetTag("test.result.explanation", stateProperty.Explanation); if (exception is not null) { - activity.SetTag("test.result.exception.type", exception.GetType().FullName); - activity.SetTag("test.result.exception.message", exception.Message); - activity.SetTag("test.result.exception.stacktrace", exception.StackTrace); + // The OpenTelemetry convention is an "exception" event carrying the type/message/stack trace, plus + // error.type and a status of Error on the span so it shows up as failed in every backend. + // error.message is deliberately not set: it is deprecated upstream and NOT RECOMMENDED on spans + // because of its unbounded cardinality - the message is on the event instead. + string? exceptionTypeName = exception.GetType().FullName; + string? truncatedMessage = _options.Truncate(exception.Message); + string? truncatedStackTrace = _options.Truncate(exception.StackTrace); + string? truncatedExceptionStackTrace = _options.Truncate(exception.ToString()); + + activity.AddEvent( + ExceptionEventName, + [ + new(ExceptionTypeTag, exceptionTypeName), + new(ExceptionMessageTag, truncatedMessage), + new(ExceptionStackTraceTag, truncatedExceptionStackTrace), + ]); + activity.SetStatus(PlatformActivityStatusCode.Error, truncatedMessage); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.ErrorType, exceptionTypeName); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.CodeStacktrace, truncatedStackTrace); + + if (_options.EmitLegacyAttributes) + { + activity.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestResultExceptionType, exceptionTypeName); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestResultExceptionMessage, truncatedMessage); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestResultExceptionStackTrace, truncatedStackTrace); + } + } + else + { + activity.SetStatus( + result switch + { + TestingPlatformSemanticConventions.TestResultStatus.Pass => PlatformActivityStatusCode.Ok, + TestingPlatformSemanticConventions.TestResultStatus.Skipped or TestingPlatformSemanticConventions.TestResultStatus.Unknown => PlatformActivityStatusCode.Unset, + _ => PlatformActivityStatusCode.Error, + }, + truncatedExplanation); } if (timeoutTime is not null) { - activity.SetTag("test.result.timeout.ms", timeoutTime.Value.TotalMilliseconds); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.TestCaseTimeoutMilliseconds, timeoutTime.Value.TotalMilliseconds); + if (_options.EmitLegacyAttributes) + { + activity.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestResultTimeout, timeoutTime.Value.TotalMilliseconds); + } + } + + try + { + SetResultDetails(testNode, measurementTags, activity); } + finally + { + // The span was already dequeued, so it must be closed even if collecting the details throws on a + // malformed property bag; otherwise it would stay open until the handler is disposed. + activity.Dispose(); + } + } + /// + /// Collects the timing, output and artifact details of a completed test in a single pass over the property bag. + /// + private void SetResultDetails(TestNode testNode, KeyValuePair[] measurementTags, IPlatformActivity? activity) + { // Single pass over the property bag: replaces five separate walks // (SingleOrDefault, OfType, SingleOrDefault, // SingleOrDefault, OfType). @@ -210,7 +496,12 @@ private void HandleTestResult(TestNode testNode, TestNodeStateProperty stateProp timingProperty = tp; break; case TestMetadataProperty metadataProperty: - activity.SetTag($"test.metadataProperty.{metadataProperty.Key}", metadataProperty.Value); + activity?.SetTag($"{TestingPlatformSemanticConventions.Attributes.TestMetadataPrefix}{metadataProperty.Key}", metadataProperty.Value); + if (_options.EmitLegacyAttributes) + { + activity?.SetTag($"{TestingPlatformSemanticConventions.Attributes.LegacyTestMetadataPrefix}{metadataProperty.Key}", metadataProperty.Value); + } + break; case StandardOutputProperty outputProperty: if (standardOutputProperty is not null) @@ -229,7 +520,7 @@ private void HandleTestResult(TestNode testNode, TestNodeStateProperty stateProp standardErrorProperty = errorProperty; break; case FileArtifactProperty fileArtifactProperty: - activity.SetTag($"test.artifact.file[{artifactIndex}].path", fileArtifactProperty.FileInfo.FullName); + activity?.SetTag($"test.artifact.file[{artifactIndex}].path", fileArtifactProperty.FileInfo.FullName); artifactIndex++; break; } @@ -238,18 +529,43 @@ private void HandleTestResult(TestNode testNode, TestNodeStateProperty stateProp if (timingProperty is not null) { double totalMilliseconds = timingProperty.GlobalTiming.Duration.TotalMilliseconds; - _totalDuration.Record(totalMilliseconds); - activity.SetTag("test.duration.ms", totalMilliseconds); + _testCaseDuration.Record(timingProperty.GlobalTiming.Duration.TotalSeconds, measurementTags); + _totalDuration?.Record(totalMilliseconds); + activity?.SetTag(TestingPlatformSemanticConventions.Attributes.TestCaseDurationMilliseconds, totalMilliseconds); + if (_options.EmitLegacyAttributes) + { + activity?.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestDuration, totalMilliseconds); + } + foreach (StepTimingInfo step in timingProperty.StepTimings) { - activity.SetTag($"test.step{step.Id}.duration.ms", step.Timing.Duration.TotalMilliseconds); - activity.SetTag($"test.step{step.Id}.description", step.Description); + activity?.SetTag($"{TestingPlatformSemanticConventions.Attributes.TestStepPrefix}{step.Id}.duration", step.Timing.Duration.TotalMilliseconds); + activity?.SetTag($"{TestingPlatformSemanticConventions.Attributes.TestStepPrefix}{step.Id}.description", step.Description); + if (_options.EmitLegacyAttributes) + { + activity?.SetTag($"test.step{step.Id}.duration.ms", step.Timing.Duration.TotalMilliseconds); + activity?.SetTag($"test.step{step.Id}.description", step.Description); + } } } - activity.SetTag("test.stdout", standardOutputProperty?.StandardOutput ?? string.Empty); - activity.SetTag("test.stderr", standardErrorProperty?.StandardError ?? string.Empty); + if (activity is null || !_options.CaptureTestOutput) + { + return; + } + + // Truncated for both the semantic-convention and the legacy names: test output routinely runs to megabytes + // and can contain secrets. + string standardOutput = _options.Truncate(standardOutputProperty?.StandardOutput) ?? string.Empty; + string standardError = _options.Truncate(standardErrorProperty?.StandardError) ?? string.Empty; + + activity.SetTag(TestingPlatformSemanticConventions.Attributes.TestOutputStdout, standardOutput); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.TestOutputStderr, standardError); - activity.Dispose(); + if (_options.EmitLegacyAttributes) + { + activity.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestStdout, standardOutput); + activity.SetTag(TestingPlatformSemanticConventions.Attributes.LegacyTestStderr, standardError); + } } } diff --git a/src/Platform/Microsoft.Testing.Platform/Telemetry/PlatformActivityStatusCode.cs b/src/Platform/Microsoft.Testing.Platform/Telemetry/PlatformActivityStatusCode.cs new file mode 100644 index 0000000000..d0c40047e8 --- /dev/null +++ b/src/Platform/Microsoft.Testing.Platform/Telemetry/PlatformActivityStatusCode.cs @@ -0,0 +1,25 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +namespace Microsoft.Testing.Platform.Telemetry; + +/// +/// Mirrors System.Diagnostics.ActivityStatusCode without taking a dependency on it. +/// +internal enum PlatformActivityStatusCode +{ + /// + /// The operation completed with an undetermined outcome. + /// + Unset, + + /// + /// The operation completed successfully. + /// + Ok, + + /// + /// The operation failed. + /// + Error, +} diff --git a/src/Platform/Microsoft.Testing.Platform/Telemetry/PlatformOpenTelemetryOptions.cs b/src/Platform/Microsoft.Testing.Platform/Telemetry/PlatformOpenTelemetryOptions.cs new file mode 100644 index 0000000000..5fe3b44c30 --- /dev/null +++ b/src/Platform/Microsoft.Testing.Platform/Telemetry/PlatformOpenTelemetryOptions.cs @@ -0,0 +1,79 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using Microsoft.Testing.Platform.Helpers; + +namespace Microsoft.Testing.Platform.Telemetry; + +/// +/// Knobs that control how much detail the platform puts on OpenTelemetry spans and metrics. +/// +/// +/// Test output and stack traces can be very large and can contain secrets, so they are opt-out-able and always +/// truncated. Everything is driven by environment variables rather than command line options so the same +/// configuration can be applied to a whole CI job without touching each invocation. +/// +internal sealed class PlatformOpenTelemetryOptions +{ + internal const int DefaultAttributeValueLengthLimit = 8 * 1024; + + private PlatformOpenTelemetryOptions(bool captureTestOutput, int attributeValueLengthLimit, bool emitLegacyAttributes) + { + CaptureTestOutput = captureTestOutput; + AttributeValueLengthLimit = attributeValueLengthLimit; + EmitLegacyAttributes = emitLegacyAttributes; + } + + /// + /// Gets a value indicating whether standard output/error captured for a test is attached to its span. + /// + public bool CaptureTestOutput { get; } + + /// + /// Gets the maximum number of characters kept for a single string attribute. Longer values are truncated + /// and suffixed with an ellipsis. + /// + public int AttributeValueLengthLimit { get; } + + /// + /// Gets a value indicating whether the pre-semantic-convention attribute and instrument names are emitted + /// alongside the new ones. Keeping them on by default means existing dashboards do not break. + /// + public bool EmitLegacyAttributes { get; } + + public static PlatformOpenTelemetryOptions Default { get; } = new(captureTestOutput: true, DefaultAttributeValueLengthLimit, emitLegacyAttributes: true); + + public static PlatformOpenTelemetryOptions FromEnvironment(IEnvironment environment) + { + bool captureTestOutput = GetBoolean(environment, EnvironmentVariableConstants.TESTINGPLATFORM_OTEL_CAPTURE_TEST_OUTPUT, defaultValue: true); + bool emitLegacyAttributes = GetBoolean(environment, EnvironmentVariableConstants.TESTINGPLATFORM_OTEL_EMIT_LEGACY_ATTRIBUTES, defaultValue: true); + + int limit = DefaultAttributeValueLengthLimit; + if (int.TryParse(environment.GetEnvironmentVariable(EnvironmentVariableConstants.TESTINGPLATFORM_OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT), out int parsedLimit) + && parsedLimit > 0) + { + limit = parsedLimit; + } + + return new PlatformOpenTelemetryOptions(captureTestOutput, limit, emitLegacyAttributes); + } + + /// + /// Truncates to . + /// + public string? Truncate(string? value) + => value is not null && value.Length > AttributeValueLengthLimit + ? value.Substring(0, AttributeValueLengthLimit) + "…" + : value; + + private static bool GetBoolean(IEnvironment environment, string name, bool defaultValue) + { + string? value = environment.GetEnvironmentVariable(name); + return value switch + { + "1" or "true" or "True" or "TRUE" => true, + "0" or "false" or "False" or "FALSE" => false, + _ => defaultValue, + }; + } +} diff --git a/src/Platform/Microsoft.Testing.Platform/Telemetry/TestingPlatformSemanticConventions.cs b/src/Platform/Microsoft.Testing.Platform/Telemetry/TestingPlatformSemanticConventions.cs new file mode 100644 index 0000000000..8fa86b1066 --- /dev/null +++ b/src/Platform/Microsoft.Testing.Platform/Telemetry/TestingPlatformSemanticConventions.cs @@ -0,0 +1,172 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +namespace Microsoft.Testing.Platform.Telemetry; + +/// +/// Well-known attribute and instrument names emitted by Microsoft.Testing.Platform. +/// +/// +/// +/// Where an OpenTelemetry semantic convention exists, its exact name is used: test.*, code.*, +/// error.*, cicd.*, vcs.*, host.*, os.* and process.*. Several of those +/// are still at "development" or "release candidate" stability upstream, so keeping every name in one file means a +/// rename upstream is a single-file change here. +/// +/// +/// Names marked "platform extension" below have no upstream definition as of semantic conventions 1.43.0 - +/// notably there are no upstream test.* metrics at all, and no upstream span conventions for test cases. +/// They deliberately sit in the test.* namespace because that is where an upstream definition would land, +/// and they are documented as ours rather than presented as standard. +/// +/// +internal static class TestingPlatformSemanticConventions +{ + /// + /// Attribute names. + /// + internal static class Attributes + { + // ---- test.* (OpenTelemetry semantic conventions for testing, development stability) ---- + internal const string TestCaseName = "test.case.name"; + internal const string TestCaseResultStatus = "test.case.result.status"; + internal const string TestSuiteName = "test.suite.name"; + + // ---- code.* (stable) ---- + // The convention asks for the *fully qualified* name here; there is no separate namespace attribute + // (code.namespace is deprecated upstream). + internal const string CodeFunctionName = "code.function.name"; + internal const string CodeFilePath = "code.file.path"; + internal const string CodeLineNumber = "code.line.number"; + internal const string CodeStacktrace = "code.stacktrace"; + + // ---- error.* (stable) ---- + // Only error.type: error.message is deprecated upstream and is NOT RECOMMENDED on spans because of its + // unbounded cardinality. The message travels on the exception event instead. + internal const string ErrorType = "error.type"; + + // ---- Platform extensions: no upstream definition ---- + internal const string TestCaseId = "test.case.id"; + internal const string TestCaseParentId = "test.case.parent.id"; + internal const string TestCaseResultExplanation = "test.case.result.explanation"; + internal const string TestCaseTimeoutMilliseconds = "test.case.timeout"; + + // Deliberately not "test.case.duration": that name belongs to the seconds-valued histogram, and reusing it + // for a milliseconds-valued span attribute would make any uniform query wrong by a factor of 1000. + internal const string TestCaseDurationMilliseconds = "test.case.duration_ms"; + internal const string TestCaseRetryAttempt = "test.case.retry.attempt"; + internal const string TestAssemblyName = "test.assembly.name"; + internal const string TestFrameworkName = "test.framework.name"; + internal const string TestFrameworkVersion = "test.framework.version"; + internal const string TestSessionId = "test.session.id"; + internal const string TestHostType = "test.host.type"; + internal const string TestRunExitCode = "test.run.exit_code"; + internal const string TestRunResultStatus = "test.run.result.status"; + internal const string TestRunTotalCount = "test.run.total"; + internal const string TestRunFailedCount = "test.run.failed"; + internal const string TestRunSkippedCount = "test.run.skipped"; + internal const string TestRunRequestType = "test.run.request_type"; + internal const string TestExtensionUid = "test.extension.uid"; + internal const string TestExtensionVersion = "test.extension.version"; + internal const string TestExtensionDisplayName = "test.extension.display_name"; + internal const string TestOutputStdout = "test.output.stdout"; + internal const string TestOutputStderr = "test.output.stderr"; + internal const string TestStepPrefix = "test.step."; + internal const string TestMetadataPrefix = "test.metadata."; + + // ---- Legacy attribute names kept for backward compatibility ---- + // Emitted alongside the semantic-convention names so existing dashboards keep working. + internal const string LegacyTestName = "test.name"; + internal const string LegacyTestId = "test.id"; + internal const string LegacyTestParentId = "test.parent.id"; + internal const string LegacyTestMethod = "test.method"; + internal const string LegacyTestClass = "test.class"; + internal const string LegacyTestNamespace = "test.namespace"; + internal const string LegacyTestAssembly = "test.assembly"; + internal const string LegacyTestFilePath = "test.file.path"; + internal const string LegacyTestLineStart = "test.line.start"; + internal const string LegacyTestLineEnd = "test.line.end"; + internal const string LegacyTestResult = "test.result"; + internal const string LegacyTestResultExplanation = "test.result.explanation"; + internal const string LegacyTestResultExceptionType = "test.result.exception.type"; + internal const string LegacyTestResultExceptionMessage = "test.result.exception.message"; + internal const string LegacyTestResultExceptionStackTrace = "test.result.exception.stacktrace"; + internal const string LegacyTestResultTimeout = "test.result.timeout.ms"; + internal const string LegacyTestDuration = "test.duration.ms"; + internal const string LegacyTestStdout = "test.stdout"; + internal const string LegacyTestStderr = "test.stderr"; + internal const string LegacyTestMetadataPrefix = "test.metadataProperty."; + } + + /// + /// Values for . + /// + /// + /// Upstream defines exactly two well-known values, pass and fail. The remaining values are + /// custom (the specification explicitly allows that) because collapsing "skipped", "timed out" and "errored" + /// into "fail" would lose the distinction a test report is built on. + /// + internal static class TestResultStatus + { + internal const string Pass = "pass"; + internal const string Fail = "fail"; + internal const string Skipped = "skipped"; + internal const string Error = "error"; + internal const string Timeout = "timeout"; + internal const string Cancelled = "cancelled"; + internal const string Unknown = "unknown"; + + /// + /// Maps a status onto the value the pre-4.x test.result attribute used, so legacy dashboards keep + /// seeing the spellings they were built against. + /// + internal static string ToLegacy(string status) + => status switch + { + Pass => "passed", + Fail => "failed", + _ => status, + }; + } + + /// + /// Instrument (metric) names. None of these are defined upstream: semantic conventions 1.43.0 has no + /// test.* metrics. + /// + internal static class Metrics + { + internal const string TestCaseDuration = "test.case.duration"; + internal const string TestCaseResultCount = "test.case.result.count"; + internal const string TestRunDuration = "test.run.duration"; + internal const string TestRunActiveCases = "test.case.active"; + internal const string TestRetryCount = "test.case.retry.count"; + + // Legacy instruments kept for backward compatibility. + internal const string LegacyTestsDiscovered = "tests.discovered"; + internal const string LegacyTestsStarted = "tests.started"; + internal const string LegacyTestsCompleted = "tests.completed"; + internal const string LegacyTestsPassed = "tests.passed"; + internal const string LegacyTestsFailed = "tests.failed"; + internal const string LegacyTestsSkipped = "tests.skipped"; + internal const string LegacyTestsUnknown = "tests.unknown"; + internal const string LegacyTestsDuration = "tests.duration"; + } + + /// + /// Instrument units, following UCUM as required by OpenTelemetry. + /// + internal static class Units + { + internal const string Seconds = "s"; + internal const string Count = "{test}"; + } + + /// + /// Span/activity names used by the platform. + /// + internal static class Activities + { + internal const string TestHostBuilder = "TestHostBuilder"; + internal const string TestFramework = "TestFramework"; + } +} diff --git a/test/UnitTests/MSTestAdapter.PlatformServices.UnitTests/Execution/TestMethodRunnerTests.cs b/test/UnitTests/MSTestAdapter.PlatformServices.UnitTests/Execution/TestMethodRunnerTests.cs index 73e85fa179..9cd44b86da 100644 --- a/test/UnitTests/MSTestAdapter.PlatformServices.UnitTests/Execution/TestMethodRunnerTests.cs +++ b/test/UnitTests/MSTestAdapter.PlatformServices.UnitTests/Execution/TestMethodRunnerTests.cs @@ -71,6 +71,7 @@ protected override void Dispose(bool disposing) { base.Dispose(disposing); PlatformServiceProvider.Instance = null; + MSTestInstrumentation.SetActivityFactory(null); } } @@ -167,6 +168,84 @@ public async Task RunTestMethodForMultipleResultsReturnMultipleResults() results[1].Outcome.Should().Be(UnitTestOutcome.Failed); } + public async Task ExecuteForFailingTestShouldRecordReturnedFailureExceptionOnActivity() + { + var failureException = new InvalidOperationException("failed"); + var activity = new FakeActivity(); + MSTestInstrumentation.SetActivityFactory((_, _) => activity); + var testMethodInfo = new TestableTestMethodInfo( + _methodInfo, + _testClassInfo, + _testMethodOptions, + () => new TestResult + { + Outcome = UnitTestOutcome.Failed, + TestFailureException = failureException, + }); + var testMethodRunner = new TestMethodRunner(testMethodInfo, _testMethod, _testContextImplementation); + + TestResult[] results = await testMethodRunner.ExecuteAsync(string.Empty, string.Empty, string.Empty, string.Empty); + + results[0].Outcome.Should().Be(UnitTestOutcome.Failed); + activity.Tags.Should().Contain(new KeyValuePair("test.case.result.status", "fail")); + activity.RecordedException.Should().BeSameAs(failureException); + activity.FailureDescription.Should().BeNull(); + } + + public async Task ExecuteForFailingTestWithoutFailureExceptionShouldSetActivityFailureStatus() + { + var activity = new FakeActivity(); + MSTestInstrumentation.SetActivityFactory((_, _) => activity); + var testMethodInfo = new TestableTestMethodInfo( + _methodInfo, + _testClassInfo, + _testMethodOptions, + () => new TestResult { Outcome = UnitTestOutcome.Failed }); + var testMethodRunner = new TestMethodRunner(testMethodInfo, _testMethod, _testContextImplementation); + + TestResult[] results = await testMethodRunner.ExecuteAsync(string.Empty, string.Empty, string.Empty, string.Empty); + + results[0].Outcome.Should().Be(UnitTestOutcome.Failed); + activity.Tags.Should().Contain(new KeyValuePair("test.case.result.status", "fail")); + activity.RecordedException.Should().BeNull(); + activity.FailureDescription.Should().Be(nameof(UnitTestOutcome.Failed)); + } + + public async Task ExecuteForAbortedTestShouldReportFailStatusOnActivity() + { + // Aborted, Unknown and Inconclusive used to fall through to "pass" because they are neither in the + // failing set nor counted as skipped, which contradicted the outcome the adapter reports. + var activity = new FakeActivity(); + MSTestInstrumentation.SetActivityFactory((_, _) => activity); + var testMethodInfo = new TestableTestMethodInfo( + _methodInfo, + _testClassInfo, + _testMethodOptions, + () => new TestResult { Outcome = UnitTestOutcome.Aborted }); + var testMethodRunner = new TestMethodRunner(testMethodInfo, _testMethod, _testContextImplementation); + + await testMethodRunner.ExecuteAsync(string.Empty, string.Empty, string.Empty, string.Empty); + + activity.Tags.Should().Contain(new KeyValuePair("test.case.result.status", "fail")); + } + + public async Task ExecuteForInconclusiveTestShouldReportSkippedStatusOnActivityByDefault() + { + var activity = new FakeActivity(); + MSTestInstrumentation.SetActivityFactory((_, _) => activity); + var testMethodInfo = new TestableTestMethodInfo( + _methodInfo, + _testClassInfo, + _testMethodOptions, + () => new TestResult { Outcome = UnitTestOutcome.Inconclusive }); + var testMethodRunner = new TestMethodRunner(testMethodInfo, _testMethod, _testContextImplementation); + + await testMethodRunner.ExecuteAsync(string.Empty, string.Empty, string.Empty, string.Empty); + + // MapInconclusiveToFailed defaults to false, so the adapter reports skipped and the span must agree. + activity.Tags.Should().Contain(new KeyValuePair("test.case.result.status", "skipped")); + } + public async Task RunTestMethodForPassingTestThrowingExceptionShouldReturnTestResultWithPassedOutcome() { var testMethodInfo = new TestableTestMethodInfo(_methodInfo, _testClassInfo, _testMethodOptions, () => new TestResult { Outcome = UnitTestOutcome.Passed }); @@ -543,6 +622,28 @@ public async Task RunTestMethodShouldNotLeakPropertyBagMutationsAcrossFoldedData #region Test data + private sealed class FakeActivity : IMSTestActivity + { + public List> Tags { get; } = []; + + public string? FailureDescription { get; private set; } + + public Exception? RecordedException { get; private set; } + + public void SetTag(string key, object? value) + => Tags.Add(new KeyValuePair(key, value)); + + public void SetFailed(string? description) + => FailureDescription = description; + + public void RecordException(Exception exception) + => RecordedException = exception; + + public void Dispose() + { + } + } + private sealed class ExecutionContextUnsafeThreadTestMethodAttribute : TestMethodAttribute { private static readonly TimeSpan WaitTimeout = TimeSpan.FromSeconds(10); diff --git a/test/UnitTests/MSTestAdapter.PlatformServices.UnitTests/MSTestInstrumentationTests.cs b/test/UnitTests/MSTestAdapter.PlatformServices.UnitTests/MSTestInstrumentationTests.cs new file mode 100644 index 0000000000..02e01c0166 --- /dev/null +++ b/test/UnitTests/MSTestAdapter.PlatformServices.UnitTests/MSTestInstrumentationTests.cs @@ -0,0 +1,119 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using AwesomeAssertions; + +using Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter; + +using TestFramework.ForTestingMSTest; + +namespace MSTestAdapter.PlatformServices.UnitTests; + +/// +/// Guards the engine-side tracing seam: it must be completely inert until a host installs a factory (which is the +/// case under VSTest and whenever the OpenTelemetry extension is not registered), and it must not build any tag +/// payload in that state. +/// +public sealed class MSTestInstrumentationTests : TestContainer +{ + protected override void Dispose(bool disposing) + { + MSTestInstrumentation.SetActivityFactory(null); + base.Dispose(disposing); + } + + public void IsEnabledIsFalseAndStartActivityReturnsNullWhenNoFactoryIsInstalled() + { + MSTestInstrumentation.SetActivityFactory(null); + + MSTestInstrumentation.IsEnabled.Should().BeFalse(); + MSTestInstrumentation.StartActivity("name").Should().BeNull(); + MSTestInstrumentation.StartFixtureActivity("name", "kind", "Type", "Assembly").Should().BeNull(); + } + + public void StartFixtureActivityDoesNotBuildTagsWhenNoFactoryIsInstalled() + { + MSTestInstrumentation.SetActivityFactory(null); + + // A throwing argument expression would surface if the seam evaluated its inputs; the point of the guard at + // the call sites is that it does not even get that far. + MSTestInstrumentation.StartFixtureActivity( + MSTestInstrumentation.ActivityNames.ClassInitialize, + "class_initialize", + owningType: null, + assemblyName: null).Should().BeNull(); + } + + public void StartFixtureActivityForwardsTheConventionalTags() + { + List>? capturedTags = null; + string? capturedName = null; + MSTestInstrumentation.SetActivityFactory((name, tags) => + { + capturedName = name; + capturedTags = tags is null ? null : [.. tags]; + return new FakeActivity(); + }); + + using IMSTestActivity? activity = MSTestInstrumentation.StartFixtureActivity( + MSTestInstrumentation.ActivityNames.AssemblyInitialize, + "assembly_initialize", + "My.Namespace.MyClass", + "MyAssembly"); + + activity.Should().NotBeNull(); + MSTestInstrumentation.IsEnabled.Should().BeTrue(); + capturedName.Should().Be("MSTest.AssemblyInitialize"); + capturedTags.Should().Contain(new KeyValuePair("test.fixture.kind", "assembly_initialize")); + capturedTags.Should().Contain(new KeyValuePair("test.suite.name", "My.Namespace.MyClass")); + capturedTags.Should().Contain(new KeyValuePair("test.assembly.name", "MyAssembly")); + } + + public void SetActivityFactoryWithNullDisablesAPreviouslyInstalledFactory() + { + MSTestInstrumentation.SetActivityFactory((_, _) => new FakeActivity()); + MSTestInstrumentation.IsEnabled.Should().BeTrue(); + + MSTestInstrumentation.SetActivityFactory(null); + + MSTestInstrumentation.IsEnabled.Should().BeFalse(); + MSTestInstrumentation.StartActivity("name").Should().BeNull(); + } + + public void StartedActivityForwardsFailureSignalsToTheReturnedActivity() + { + FakeActivity? capturedActivity = null; + MSTestInstrumentation.SetActivityFactory((_, _) => capturedActivity = new FakeActivity()); + var exception = new InvalidOperationException("Boom"); + + using IMSTestActivity? activity = MSTestInstrumentation.StartActivity("name"); + activity.Should().NotBeNull(); + activity!.SetFailed("Failed"); + activity.RecordException(exception); + + capturedActivity.Should().NotBeNull(); + capturedActivity!.FailureDescription.Should().Be("Failed"); + capturedActivity.RecordedException.Should().BeSameAs(exception); + } + + private sealed class FakeActivity : IMSTestActivity + { + public string? FailureDescription { get; private set; } + + public Exception? RecordedException { get; private set; } + + public void SetTag(string key, object? value) + { + } + + public void SetFailed(string? description) + => FailureDescription = description; + + public void RecordException(Exception exception) + => RecordedException = exception; + + public void Dispose() + { + } + } +} diff --git a/test/UnitTests/Microsoft.Testing.Extensions.UnitTests/Microsoft.Testing.Extensions.UnitTests.csproj b/test/UnitTests/Microsoft.Testing.Extensions.UnitTests/Microsoft.Testing.Extensions.UnitTests.csproj index e37b30926d..1beb36a993 100644 --- a/test/UnitTests/Microsoft.Testing.Extensions.UnitTests/Microsoft.Testing.Extensions.UnitTests.csproj +++ b/test/UnitTests/Microsoft.Testing.Extensions.UnitTests/Microsoft.Testing.Extensions.UnitTests.csproj @@ -58,6 +58,9 @@ TargetFramework=netstandard2.0 + + TargetFramework=netstandard2.0 + diff --git a/test/UnitTests/Microsoft.Testing.Extensions.UnitTests/OpenTelemetryPlatformServiceTests.cs b/test/UnitTests/Microsoft.Testing.Extensions.UnitTests/OpenTelemetryPlatformServiceTests.cs new file mode 100644 index 0000000000..aa1b6c9e1a --- /dev/null +++ b/test/UnitTests/Microsoft.Testing.Extensions.UnitTests/OpenTelemetryPlatformServiceTests.cs @@ -0,0 +1,192 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using System.Diagnostics; + +using Microsoft.Testing.Extensions.OpenTelemetry; +using Microsoft.Testing.Platform.Telemetry; + +namespace Microsoft.Testing.Extensions.UnitTests; + +/// +/// Exercises the real against a live , +/// which is the only way to cover the ambient-context behaviour that the mock-based platform tests cannot see. +/// +/// +/// and the listener registry are process-global and the test host may already have +/// an ambient activity of its own, so every assertion is made relative to the activity that was current when the +/// test started, and the listener only collects activities this instance created (identified by a unique name +/// prefix). +/// +[TestClass] +public sealed class OpenTelemetryPlatformServiceTests : IDisposable +{ + private readonly string _namePrefix = $"test-{Guid.NewGuid():N}-"; + private readonly List _stoppedActivities = []; + private readonly Activity? _ambientAtStart = Activity.Current; + private readonly ActivityListener _listener; + private readonly OpenTelemetryPlatformService _service = new(); + + public OpenTelemetryPlatformServiceTests() + { + _listener = new ActivityListener + { + ShouldListenTo = source => source.Name == OpenTelemetryPlatformService.ActivitySourceName, + Sample = (ref _) => ActivitySamplingResult.AllDataAndRecorded, + ActivityStopped = activity => + { + if (activity.OperationName.StartsWith(_namePrefix, StringComparison.Ordinal)) + { + lock (_stoppedActivities) + { + _stoppedActivities.Add(activity); + } + } + }, + }; + ActivitySource.AddActivityListener(_listener); + } + + public void Dispose() + { + _listener.Dispose(); + _service.Dispose(); + } + + [TestMethod] + public void StartActivity_ByDefault_PublishesTheActivityAsCurrent() + { + using (_service.StartActivity(Name("ambient"))) + { + Assert.IsNotNull(Activity.Current); + Assert.AreEqual(Name("ambient"), Activity.Current.OperationName); + Assert.IsTrue(_service.HasCurrentActivity); + } + + Assert.AreSame(_ambientAtStart, Activity.Current); + } + + [TestMethod] + public void StartNonAmbientActivity_NeverBecomesCurrent() + { + // This is what keeps MSTest fixture spans out of the ExecutionContext that MSTest captures inside a + // fixture and replays for the rest of the run. + using (_service.StartNonAmbientActivity(Name("non-ambient"))) + { + Assert.AreSame(_ambientAtStart, Activity.Current); + } + + Assert.AreSame(_ambientAtStart, Activity.Current); + + // The span is still timed and exported even though it was never current. + Assert.AreEqual(Name("non-ambient"), Single().OperationName); + } + + [TestMethod] + public void StartNonAmbientActivity_DoesNotDisturbAnExistingAmbientActivity() + { + using (_service.StartActivity(Name("outer"))) + { + Activity? ambient = Activity.Current; + Assert.IsNotNull(ambient); + + using (_service.StartNonAmbientActivity(Name("inner"))) + { + Assert.AreSame(ambient, Activity.Current); + } + + // Stopping a non-ambient activity must not pop the ambient one. + Assert.AreSame(ambient, Activity.Current); + } + + Assert.AreSame(_ambientAtStart, Activity.Current); + } + + [TestMethod] + public void StartNonAmbientActivity_WithExplicitParentId_KeepsTheSameTrace() + { + using IPlatformActivity? parent = _service.StartActivity(Name("parent")); + Assert.IsNotNull(parent); + Assert.IsNotNull(parent.Id); + + using IPlatformActivity? child = _service.StartNonAmbientActivity(Name("child"), parentId: parent.Id); + Assert.IsNotNull(child); + Assert.AreEqual(parent.TraceId, child.TraceId); + Assert.AreNotEqual(parent.SpanId, child.SpanId); + } + + [TestMethod] + public void SetStatus_MapsOntoActivityStatusCode() + { + using (IPlatformActivity? activity = _service.StartActivity(Name("status"))) + { + Assert.IsNotNull(activity); + activity.SetStatus(PlatformActivityStatusCode.Error, "it broke"); + } + + Activity stopped = Single(); + Assert.AreEqual(ActivityStatusCode.Error, stopped.Status); + Assert.AreEqual("it broke", stopped.StatusDescription); + } + + [TestMethod] + public void RecordException_AddsTheConventionalExceptionEventAndFailsTheSpan() + { + InvalidOperationException exception = new("boom"); + + using (IPlatformActivity? activity = _service.StartActivity(Name("exception"))) + { + Assert.IsNotNull(activity); + activity.RecordException(exception); + } + + Activity stopped = Single(); + Assert.AreEqual(ActivityStatusCode.Error, stopped.Status); + + ActivityEvent exceptionEvent = stopped.Events.Single(); + Assert.AreEqual("exception", exceptionEvent.Name); + Assert.AreEqual(typeof(InvalidOperationException).FullName, GetTag(exceptionEvent, "exception.type")); + Assert.AreEqual("boom", GetTag(exceptionEvent, "exception.message")); + Assert.IsNotNull(GetTag(exceptionEvent, "exception.stacktrace")); + } + + [TestMethod] + public void AddEvent_AddsANamedEventWithItsTags() + { + using (IPlatformActivity? activity = _service.StartActivity(Name("events"))) + { + Assert.IsNotNull(activity); + activity.AddEvent("hang.detected", [new("dump.path", "a.dmp")]); + } + + ActivityEvent activityEvent = Single().Events.Single(); + Assert.AreEqual("hang.detected", activityEvent.Name); + Assert.AreEqual("a.dmp", GetTag(activityEvent, "dump.path")); + } + + [TestMethod] + public void StartActivity_SetsTheTagsProvidedAtCreation() + { + using (_service.StartActivity(Name("tags"), tags: [new("test.case.name", "MyTest")])) + { + } + + Assert.AreEqual("MyTest", Single().GetTagItem("test.case.name")); + } + + private static object? GetTag(ActivityEvent activityEvent, string key) + => activityEvent.Tags + .Where(tag => tag.Key == key) + .Select(tag => tag.Value) + .FirstOrDefault(); + + private string Name(string name) => _namePrefix + name; + + private Activity Single() + { + lock (_stoppedActivities) + { + return _stoppedActivities.Single(); + } + } +} diff --git a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Services/TestApplicationResultTests.cs b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Services/TestApplicationResultTests.cs index 12c890ef8a..a1bfa406f3 100644 --- a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Services/TestApplicationResultTests.cs +++ b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Services/TestApplicationResultTests.cs @@ -27,10 +27,13 @@ public async Task ConsumeAsync_ExecutionCompleted_ClosesOnlyOldestActivityWithou var secondActivity = new Mock(); var otelService = new Mock(); otelService - .Setup(service => service.CreateCounter(It.IsAny(), null, null, null)) + .Setup(service => service.CreateCounter(It.IsAny(), It.IsAny(), It.IsAny(), It.IsAny>?>())) .Returns(Mock.Of>()); otelService - .Setup(service => service.CreateHistogram(It.IsAny(), null, null, null)) + .Setup(service => service.CreateUpDownCounter(It.IsAny(), It.IsAny(), It.IsAny(), It.IsAny>?>())) + .Returns(Mock.Of>()); + otelService + .Setup(service => service.CreateHistogram(It.IsAny(), It.IsAny(), It.IsAny(), It.IsAny>?>())) .Returns(Mock.Of>()); otelService .SetupSequence(service => service.StartActivity( diff --git a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Telemetry/EnvironmentTraceContextTests.cs b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Telemetry/EnvironmentTraceContextTests.cs new file mode 100644 index 0000000000..21627cb384 --- /dev/null +++ b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Telemetry/EnvironmentTraceContextTests.cs @@ -0,0 +1,100 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using Microsoft.Testing.Platform.Helpers; +using Microsoft.Testing.Platform.Telemetry; + +using Moq; + +namespace Microsoft.Testing.Platform.UnitTests; + +[TestClass] +public sealed class EnvironmentTraceContextTests +{ + private const string ValidTraceParent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + + [TestMethod] + [DataRow(ValidTraceParent)] + [DataRow("01-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-00")] + public void IsValidTraceParent_WithWellFormedValue_ReturnsTrue(string traceParent) + => Assert.IsTrue(EnvironmentTraceContext.IsValidTraceParent(traceParent)); + + [TestMethod] + [DataRow(null)] + [DataRow("")] + [DataRow("garbage")] + // Wrong length. + [DataRow("00-0af7651916cd43dd8448eb211c80319c-b7ad6b716920333-01")] + // Missing separators. + [DataRow("000af7651916cd43dd8448eb211c80319cb7ad6b716920333101")] + // Non-hex character in the trace id. + [DataRow("00-0zf7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01")] + // Uppercase hex: System.Diagnostics requires lowercase and silently starts a new trace otherwise. + [DataRow("00-0AF7651916CD43DD8448EB211C80319C-B7AD6B7169203331-01")] + // Version 'ff' is forbidden by the W3C specification and rejected by System.Diagnostics. + [DataRow("ff-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01")] + // All-zero trace id is invalid per the W3C specification. + [DataRow("00-00000000000000000000000000000000-b7ad6b7169203331-01")] + // All-zero span id is invalid per the W3C specification. + [DataRow("00-0af7651916cd43dd8448eb211c80319c-0000000000000000-01")] + public void IsValidTraceParent_WithMalformedValue_ReturnsFalse(string? traceParent) + => Assert.IsFalse(EnvironmentTraceContext.IsValidTraceParent(traceParent)); + + [TestMethod] + public void TryGetParentId_ReadsTraceParentFromEnvironment() + { + Mock environment = new(); + environment.Setup(e => e.GetEnvironmentVariable("TRACEPARENT")).Returns(ValidTraceParent); + + Assert.AreEqual(ValidTraceParent, EnvironmentTraceContext.TryGetParentId(environment.Object)); + } + + [TestMethod] + public void TryGetParentId_PrefersTraceParentOverTheTestingPlatformSpecificVariable() + { + const string otherTraceParent = "00-11111111111111111111111111111111-2222222222222222-01"; + Mock environment = new(); + environment.Setup(e => e.GetEnvironmentVariable("TRACEPARENT")).Returns(ValidTraceParent); + environment.Setup(e => e.GetEnvironmentVariable("TESTINGPLATFORM_TRACEPARENT")).Returns(otherTraceParent); + + Assert.AreEqual(ValidTraceParent, EnvironmentTraceContext.TryGetParentId(environment.Object)); + } + + [TestMethod] + public void TryGetParentId_FallsBackToTheTestingPlatformSpecificVariable() + { + Mock environment = new(); + environment.Setup(e => e.GetEnvironmentVariable("TRACEPARENT")).Returns((string?)null); + environment.Setup(e => e.GetEnvironmentVariable("TESTINGPLATFORM_TRACEPARENT")).Returns(ValidTraceParent); + + Assert.AreEqual(ValidTraceParent, EnvironmentTraceContext.TryGetParentId(environment.Object)); + } + + [TestMethod] + public void TryGetParentId_WithMalformedValue_ReturnsNull() + { + // A malformed variable must not poison the trace: System.Diagnostics silently drops invalid parent ids, + // which is much harder to diagnose than simply starting a new root trace. + Mock environment = new(); + environment.Setup(e => e.GetEnvironmentVariable("TRACEPARENT")).Returns("not-a-traceparent"); + + Assert.IsNull(EnvironmentTraceContext.TryGetParentId(environment.Object)); + } + + [TestMethod] + public void TryGetTraceState_ReturnsNullWhenUnset() + { + Mock environment = new(); + + Assert.IsNull(EnvironmentTraceContext.TryGetTraceState(environment.Object)); + } + + [TestMethod] + public void TryGetTraceState_ReturnsTrimmedValue() + { + Mock environment = new(); + environment.Setup(e => e.GetEnvironmentVariable("TRACESTATE")).Returns(" vendor=value "); + + Assert.AreEqual("vendor=value", EnvironmentTraceContext.TryGetTraceState(environment.Object)); + } +} diff --git a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Telemetry/OpenTelemetryResultHandlerTests.cs b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Telemetry/OpenTelemetryResultHandlerTests.cs index ff31b56f42..50062b0704 100644 --- a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Telemetry/OpenTelemetryResultHandlerTests.cs +++ b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/Telemetry/OpenTelemetryResultHandlerTests.cs @@ -2,6 +2,7 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using Microsoft.Testing.Platform.Extensions.Messages; +using Microsoft.Testing.Platform.Helpers; using Microsoft.Testing.Platform.Telemetry; using Moq; @@ -19,7 +20,11 @@ public sealed class OpenTelemetryResultHandlerTests : IDisposable private readonly FakeCounter _failedCounter = new(); private readonly FakeCounter _skippedCounter = new(); private readonly FakeCounter _unknownCounter = new(); + private readonly FakeCounter _testCaseResultCounter = new(); + private readonly FakeUpDownCounter _activeTestCases = new(); private readonly FakeHistogram _durationHistogram = new(); + private readonly FakeHistogram _testCaseDurationHistogram = new(); + private readonly FakeHistogram _testRunDurationHistogram = new(); private readonly OpenTelemetryResultHandler _handler; public OpenTelemetryResultHandlerTests() @@ -33,6 +38,11 @@ public OpenTelemetryResultHandlerTests() _otelService.Setup(s => s.CreateCounter("tests.unknown", null, null, null)).Returns(_unknownCounter); _otelService.Setup(s => s.CreateHistogram("tests.duration", null, null, null)).Returns(_durationHistogram); + _otelService.Setup(s => s.CreateCounter("test.case.result.count", It.IsAny(), It.IsAny(), It.IsAny>?>())).Returns(_testCaseResultCounter); + _otelService.Setup(s => s.CreateUpDownCounter("test.case.active", It.IsAny(), It.IsAny(), It.IsAny>?>())).Returns(_activeTestCases); + _otelService.Setup(s => s.CreateHistogram("test.case.duration", It.IsAny(), It.IsAny(), It.IsAny>?>())).Returns(_testCaseDurationHistogram); + _otelService.Setup(s => s.CreateHistogram("test.run.duration", It.IsAny(), It.IsAny(), It.IsAny>?>())).Returns(_testRunDurationHistogram); + _handler = new OpenTelemetryResultHandler(_otelService.Object); } @@ -122,8 +132,12 @@ public void NotifyInProgress_WhenStartActivityReturnsNull_DoesNotTrackActivity() TestNode testNode = CreateTestNode(); _handler.NotifyInProgress(testNode, null); - // Should not throw when completing the test (no activity tracked). + // Should not throw when completing the test (no activity tracked), and the result must still be counted + // so that a metrics-only configuration keeps working. _handler.NotifyPassed(testNode, PassedTestNodeStateProperty.CachedInstance); + + Assert.AreEqual(1, _testCaseResultCounter.Value); + Assert.AreEqual(0, _activeTestCases.Value); } [TestMethod] @@ -266,14 +280,25 @@ public void NotifyInProgress_WithParentUid_IncludesParentIdInTags() [TestMethod] public void Dispose_DisposesOrphanedActivities() { - Mock activity1 = SetupActivityForTestNode("orphan-1"); - Mock activity2 = SetupActivityForTestNode("orphan-2"); + Mock activity1 = new(); + Mock activity2 = new(); + activity1.Setup(a => a.SetTag(It.IsAny(), It.IsAny())).Returns(activity1.Object); + activity2.Setup(a => a.SetTag(It.IsAny(), It.IsAny())).Returns(activity2.Object); + _otelService.SetupSequence(s => s.StartActivity( + It.IsAny(), + It.IsAny>?>(), + It.IsAny(), + It.IsAny())) + .Returns(activity1.Object) + .Returns(activity2.Object); _handler.NotifyInProgress(CreateTestNode("orphan-1"), null); _handler.NotifyInProgress(CreateTestNode("orphan-2"), null); + Assert.AreEqual(2, _activeTestCases.Value); _handler.Dispose(); + Assert.AreEqual(0, _activeTestCases.Value); activity1.Verify(a => a.Dispose(), Times.Once); activity2.Verify(a => a.Dispose(), Times.Once); } @@ -419,6 +444,305 @@ public void Dispose_WithMultipleActivitiesSharingUid_DisposesAllOfThem() public void Dispose() => _handler.Dispose(); + [TestMethod] + public void HandleTestResult_WithPassedState_SetsSemanticConventionStatusAndCounts() + { + Mock activity = SetupActivityForTestNode("semconv-passed"); + TestNode testNode = CreateTestNode("semconv-passed"); + + _handler.NotifyInProgress(testNode, null); + _handler.NotifyPassed(testNode, PassedTestNodeStateProperty.CachedInstance); + + // The upstream test.case.result.status enum is "pass"/"fail"; the legacy attribute keeps "passed"/"failed". + activity.Verify(a => a.SetTag("test.case.result.status", "pass"), Times.Once); + activity.Verify(a => a.SetTag("test.result", "passed"), Times.Once); + activity.Verify(a => a.SetStatus(PlatformActivityStatusCode.Ok, It.IsAny()), Times.Once); + Assert.AreEqual(1, _testCaseResultCounter.Value); + Assert.IsNotNull(_testCaseResultCounter.LastTags); + Assert.Contains(t => t.Key == "test.case.result.status" && (string?)t.Value == "pass", _testCaseResultCounter.LastTags); + } + + [TestMethod] + public void HandleTestResult_WithFailedState_RecordsExceptionAndErrorAttributes() + { + Mock activity = SetupActivityForTestNode("semconv-failed"); + string? eventName = null; + IReadOnlyList>? exceptionEventTags = null; + activity.Setup(a => a.AddEvent(It.IsAny(), It.IsAny>?>(), It.IsAny())) + .Callback>?, DateTimeOffset>((name, tags, _) => + { + eventName = name; + exceptionEventTags = tags?.ToList(); + }) + .Returns(activity.Object); + TestNode testNode = CreateTestNode("semconv-failed"); + InvalidOperationException exception = new("boom"); + + _handler.NotifyInProgress(testNode, null); + _handler.NotifyFailed(testNode, new FailedTestNodeStateProperty(exception, "test failed")); + + activity.Verify(a => a.RecordException(exception, It.IsAny>?>()), Times.Never); + Assert.AreEqual("exception", eventName); + Assert.IsNotNull(exceptionEventTags); + Assert.Contains(t => t.Key == "exception.type" && (string?)t.Value == typeof(InvalidOperationException).FullName, exceptionEventTags); + Assert.Contains(t => t.Key == "exception.message" && (string?)t.Value == "boom", exceptionEventTags); + Assert.Contains(t => t.Key == "exception.stacktrace" && (string?)t.Value == exception.ToString(), exceptionEventTags); + activity.Verify(a => a.SetStatus(PlatformActivityStatusCode.Error, "boom"), Times.Once); + activity.Verify(a => a.SetTag("error.type", typeof(InvalidOperationException).FullName), Times.Once); + + // error.message is deprecated upstream and NOT RECOMMENDED on spans; the message travels on the + // exception event and on the legacy attribute instead. + activity.Verify(a => a.SetTag("error.message", It.IsAny()), Times.Never); + activity.Verify(a => a.SetTag("test.result.exception.message", "boom"), Times.Once); + Assert.Contains(t => t.Key == "test.case.result.status" && (string?)t.Value == "fail", _testCaseResultCounter.LastTags!); + } + + [TestMethod] + public void HandleTestResult_WithTimingProperty_RecordsSecondsOnSemanticConventionHistogram() + { + SetupActivityForTestNode("semconv-duration"); + TimingInfo timing = new(DateTimeOffset.UtcNow, DateTimeOffset.UtcNow.AddSeconds(2), TimeSpan.FromSeconds(2)); + TestNode testNode = new() + { + Uid = new TestNodeUid("semconv-duration"), + DisplayName = "Test", + Properties = new PropertyBag(PassedTestNodeStateProperty.CachedInstance, new TimingProperty(timing)), + }; + + _handler.NotifyInProgress(testNode, null); + _handler.NotifyPassed(testNode, PassedTestNodeStateProperty.CachedInstance); + + // OpenTelemetry requires durations in seconds, while the legacy instrument stays in milliseconds. + Assert.AreEqual(2d, _testCaseDurationHistogram.LastRecordedValue); + Assert.AreEqual(2000d, _durationHistogram.LastRecordedValue); + } + + [TestMethod] + public void HandleTestResult_WithoutTrackedActivity_StillRecordsDurationAndCount() + { + TimingInfo timing = new(DateTimeOffset.UtcNow, DateTimeOffset.UtcNow.AddSeconds(1), TimeSpan.FromSeconds(1)); + TestNode testNode = new() + { + Uid = new TestNodeUid("no-activity"), + DisplayName = "Test", + Properties = new PropertyBag(PassedTestNodeStateProperty.CachedInstance, new TimingProperty(timing)), + }; + + // No NotifyInProgress: frameworks that only publish final results must still produce latency data. + _handler.NotifyPassed(testNode, PassedTestNodeStateProperty.CachedInstance); + + Assert.AreEqual(1d, _testCaseDurationHistogram.LastRecordedValue); + Assert.AreEqual(1, _testCaseResultCounter.Value); + } + + [TestMethod] + public void NotifyInProgress_EmitsSemanticConventionAttributes() + { + IEnumerable>? capturedTags = null; + _otelService.Setup(s => s.StartActivity( + It.IsAny(), + It.IsAny>?>(), + It.IsAny(), + It.IsAny())) + .Callback>?, string?, DateTimeOffset>((_, tags, _, _) => capturedTags = tags?.ToList()) + .Returns(new Mock().Object); + + _handler.NotifyInProgress(CreateTestNode("semconv-tags"), new TestNodeUid("parent")); + + Assert.IsNotNull(capturedTags); + var tagList = capturedTags.ToList(); + Assert.IsTrue(tagList.Exists(t => t.Key == "test.case.name" && (string?)t.Value == "Test")); + Assert.IsTrue(tagList.Exists(t => t.Key == "test.case.id" && (string?)t.Value == "semconv-tags")); + Assert.IsTrue(tagList.Exists(t => t.Key == "test.case.parent.id" && (string?)t.Value == "parent")); + } + + [TestMethod] + public void NotifyRunCompleted_RecordsRunDurationWithVerdict() + { + Mock runActivity = new(); + _handler.NotifyRunCompleted(totalRanTests: 10, failedTests: 2, skippedTests: 1, exitCode: (int)ExitCode.AtLeastOneTestFailed, runActivity.Object); + + Assert.IsNotNull(_testRunDurationHistogram.LastRecordedValue); + Assert.IsNotNull(_testRunDurationHistogram.LastTags); + + // Only bounded dimensions belong on the histogram: the raw counts would create a new time series per + // distinct value. + Assert.Contains(t => t.Key == "test.run.result.status" && (string?)t.Value == "fail", _testRunDurationHistogram.LastTags); + Assert.Contains(t => t.Key == "test.run.exit_code" && (int?)t.Value == (int)ExitCode.AtLeastOneTestFailed, _testRunDurationHistogram.LastTags); + Assert.DoesNotContain(t => t.Key == "test.run.total", _testRunDurationHistogram.LastTags); + + // The unbounded counts go on the span instead, where cardinality is free. + runActivity.Verify(a => a.SetTag("test.run.total", 10), Times.Once); + runActivity.Verify(a => a.SetTag("test.run.failed", 2), Times.Once); + runActivity.Verify(a => a.SetTag("test.run.skipped", 1), Times.Once); + } + + [TestMethod] + public void NotifyRunCompleted_WithNonSuccessExitCodeAndNoFailedTests_RecordsFailedVerdict() + { + _handler.NotifyRunCompleted(totalRanTests: 0, failedTests: 0, skippedTests: 0, exitCode: (int)ExitCode.ZeroTests); + + Assert.IsNotNull(_testRunDurationHistogram.LastTags); + Assert.Contains(t => t.Key == "test.run.result.status" && (string?)t.Value == "fail", _testRunDurationHistogram.LastTags); + Assert.Contains(t => t.Key == "test.run.exit_code" && (int?)t.Value == (int)ExitCode.ZeroTests, _testRunDurationHistogram.LastTags); + } + + [TestMethod] + public void ActiveTestCases_GoesBackToZeroWhenTestsComplete() + { + SetupActivityForTestNode("active"); + TestNode testNode = CreateTestNode("active"); + + _handler.NotifyInProgress(testNode, null); + Assert.AreEqual(1, _activeTestCases.Value); + + _handler.NotifyPassed(testNode, PassedTestNodeStateProperty.CachedInstance); + Assert.AreEqual(0, _activeTestCases.Value); + } + + [TestMethod] + public void ActiveTestCases_GoesBackToZero_WhenNoTracerIsListening() + { + // StartActivity returns null whenever nothing subscribes to the activity source, which is the normal state + // for a metrics-only configuration. The in-flight bookkeeping must not depend on a span existing. + _otelService.Setup(s => s.StartActivity( + It.IsAny(), + It.IsAny>?>(), + It.IsAny(), + It.IsAny())).Returns((IPlatformActivity?)null); + + TestNode testNode = CreateTestNode("no-tracer"); + _handler.NotifyInProgress(testNode, null); + Assert.AreEqual(1, _activeTestCases.Value); + + _handler.NotifyPassed(testNode, PassedTestNodeStateProperty.CachedInstance); + + Assert.AreEqual(0, _activeTestCases.Value); + Assert.AreEqual(1, _testCaseResultCounter.Value); + } + + [TestMethod] + public void ActiveTestCases_GoesBackToZero_WhenExecutionCompletesWithoutTracer() + { + _otelService.Setup(s => s.StartActivity( + It.IsAny(), + It.IsAny>?>(), + It.IsAny(), + It.IsAny())).Returns((IPlatformActivity?)null); + + TestNode testNode = CreateTestNode("no-tracer-completed"); + _handler.NotifyInProgress(testNode, null); + _handler.NotifyExecutionCompleted(testNode); + + Assert.AreEqual(0, _activeTestCases.Value); + } + + [TestMethod] + public void NotifyInProgress_AfterDispose_ClosesTheSpanAndDoesNotTrackIt() + { + // A cancelled run skips the message-bus drain, so a consumer can still publish results while the host is + // disposing us. That must not throw or leave a span open. + Mock activity = SetupActivityForTestNode("late"); + _handler.Dispose(); + + _handler.NotifyInProgress(CreateTestNode("late"), null); + + activity.Verify(a => a.Dispose(), Times.Once); + Assert.AreEqual(0, _activeTestCases.Value); + } + + [TestMethod] + public void Dispose_WhileResultsAreStillArriving_BalancesActiveCountAndDoesNotThrow() + { + SetupActivityForTestNode("racing"); + for (int i = 0; i < 200; i++) + { + _handler.NotifyInProgress(CreateTestNode($"racing-{i}"), null); + } + + // Concurrently completing results while disposing used to throw "collection was modified" out of the + // telemetry path during shutdown. + Task publisher = Task.Factory.StartNew( + () => + { + for (int i = 0; i < 200; i++) + { + _handler.NotifyPassed(CreateTestNode($"racing-{i}"), PassedTestNodeStateProperty.CachedInstance); + } + }, + CancellationToken.None, + TaskCreationOptions.LongRunning, + TaskScheduler.Default); + + _handler.Dispose(); + publisher.GetAwaiter().GetResult(); + + // Every in-flight entry is decremented exactly once, whether it was completed by the publisher or drained + // by Dispose, so the gauge must settle at zero no matter how the two interleave. + Assert.AreEqual(0, _activeTestCases.Value); + } + + [TestMethod] + public void NotifyRunCompleted_CalledTwice_RecordsRunDurationOnce() + { + _handler.NotifyRunCompleted(totalRanTests: 1, failedTests: 0, skippedTests: 0, exitCode: 0); + _testRunDurationHistogram.Reset(); + + _handler.NotifyRunCompleted(totalRanTests: 1, failedTests: 0, skippedTests: 0, exitCode: 0); + + Assert.IsNull(_testRunDurationHistogram.LastRecordedValue); + } + + [TestMethod] + public void NotifyInProgress_EmitsFullyQualifiedCodeFunctionName() + { + IEnumerable>? capturedTags = CaptureInProgressTags( + new TestMethodIdentifierProperty("MyAssembly", "My.Namespace", "MyClass", "MyMethod", 0, [], "void")); + + Assert.IsNotNull(capturedTags); + Assert.Contains(t => t.Key == "code.function.name" && (string?)t.Value == "My.Namespace.MyClass.MyMethod", capturedTags); + + // code.namespace is deprecated upstream and must not be emitted. + Assert.DoesNotContain(t => t.Key == "code.namespace", capturedTags); + } + + [TestMethod] + [DataRow("")] + // Roslyn's INamespaceSymbol.ToDisplayString() returns this for the global namespace, so a framework that + // does not first check IsGlobalNamespace hands us the sentinel rather than an empty string. + [DataRow("")] + public void NotifyInProgress_ForTheGlobalNamespace_DoesNotEmitALeadingDot(string @namespace) + { + IEnumerable>? capturedTags = CaptureInProgressTags( + new TestMethodIdentifierProperty("MyAssembly", @namespace, "MyClass", "MyMethod", 0, [], "void")); + + Assert.IsNotNull(capturedTags); + Assert.Contains(t => t.Key == "code.function.name" && (string?)t.Value == "MyClass.MyMethod", capturedTags); + } + + private IEnumerable>? CaptureInProgressTags(TestMethodIdentifierProperty identifierProperty) + { + IEnumerable>? capturedTags = null; + _otelService.Setup(s => s.StartActivity( + It.IsAny(), + It.IsAny>?>(), + It.IsAny(), + It.IsAny())) + .Callback>?, string?, DateTimeOffset>((_, tags, _, _) => capturedTags = tags?.ToList()) + .Returns(new Mock().Object); + + _handler.NotifyInProgress( + new TestNode + { + Uid = new TestNodeUid("fqn"), + DisplayName = "Test", + Properties = new PropertyBag(identifierProperty), + }, + null); + + return capturedTags; + } + private static TestNode CreateTestNode(string uid = "test-uid") => new() { @@ -426,13 +750,25 @@ private static TestNode CreateTestNode(string uid = "test-uid") DisplayName = "Test", }; + private static Exception CreateExceptionWithStackTrace(string message) + { + try + { + throw new InvalidOperationException(message); + } + catch (Exception exception) + { + return exception; + } + } + private Mock SetupActivityForTestNode(string testNodeUid) { Mock activity = new(); activity.SetupGet(a => a.Id).Returns($"activity-{testNodeUid}"); activity.Setup(a => a.SetTag(It.IsAny(), It.IsAny())).Returns(activity.Object); _otelService.Setup(s => s.StartActivity( - testNodeUid, + It.IsAny(), It.IsAny>?>(), It.IsAny(), It.IsAny())).Returns(activity.Object); @@ -440,6 +776,67 @@ private Mock SetupActivityForTestNode(string testNodeUid) return activity; } + [TestMethod] + public void HandleTestResult_TruncatesExceptionEventAndStatus() + { + Mock environment = new(); + environment.Setup(e => e.GetEnvironmentVariable("TESTINGPLATFORM_OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT")).Returns("10"); + using OpenTelemetryResultHandler handler = new(_otelService.Object, PlatformOpenTelemetryOptions.FromEnvironment(environment.Object)); + + Mock activity = SetupActivityForTestNode("truncated-exception"); + IReadOnlyList>? exceptionEventTags = null; + activity.Setup(a => a.AddEvent(It.IsAny(), It.IsAny>?>(), It.IsAny())) + .Callback>?, DateTimeOffset>((_, tags, _) => exceptionEventTags = tags?.ToList()) + .Returns(activity.Object); + Exception exception = CreateExceptionWithStackTrace(new string('m', 5000)); + TestNode testNode = CreateTestNode("truncated-exception"); + + handler.NotifyInProgress(testNode, null); + handler.NotifyFailed(testNode, new FailedTestNodeStateProperty(exception)); + + string expectedMessage = new string('m', 10) + "…"; + string expectedStackTrace = exception.ToString().Substring(0, 10) + "…"; + Assert.IsNotNull(exceptionEventTags); + Assert.Contains(t => t.Key == "exception.message" && (string?)t.Value == expectedMessage, exceptionEventTags); + Assert.Contains(t => t.Key == "exception.stacktrace" && (string?)t.Value == expectedStackTrace, exceptionEventTags); + activity.Verify(a => a.SetStatus(PlatformActivityStatusCode.Error, expectedMessage), Times.Once); + activity.Verify(a => a.RecordException(exception, It.IsAny>?>()), Times.Never); + } + + [TestMethod] + public void HandleTestResult_TruncatesLegacyAttributesToo() + { + // Legacy attributes are on by default, so leaving them untruncated would defeat the size limit entirely. + Mock environment = new(); + environment.Setup(e => e.GetEnvironmentVariable("TESTINGPLATFORM_OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT")).Returns("10"); + using OpenTelemetryResultHandler handler = new(_otelService.Object, PlatformOpenTelemetryOptions.FromEnvironment(environment.Object)); + + Mock activity = SetupActivityForTestNode("truncation"); + string longOutput = new('x', 5000); + TestNode testNode = new() + { + Uid = new TestNodeUid("truncation"), + DisplayName = "Test", + Properties = new PropertyBag( + PassedTestNodeStateProperty.CachedInstance, + new StandardOutputProperty(longOutput), + new StandardErrorProperty(longOutput)), + }; + + handler.NotifyInProgress(testNode, null); + handler.NotifyPassed(testNode, new PassedTestNodeStateProperty(new string('e', 5000))); + + string expected = new string('x', 10) + "…"; + activity.Verify(a => a.SetTag("test.output.stdout", expected), Times.Once); + activity.Verify(a => a.SetTag("test.stdout", expected), Times.Once); + activity.Verify(a => a.SetTag("test.output.stderr", expected), Times.Once); + activity.Verify(a => a.SetTag("test.stderr", expected), Times.Once); + + string expectedExplanation = new string('e', 10) + "…"; + activity.Verify(a => a.SetTag("test.case.result.explanation", expectedExplanation), Times.Once); + activity.Verify(a => a.SetTag("test.result.explanation", expectedExplanation), Times.Once); + } + private sealed class FakeCounter : ICounter where T : struct { @@ -447,6 +844,23 @@ private sealed class FakeCounter : ICounter public void Add(T delta) => Value = (T)(object)((int)(object)Value + (int)(object)delta); + + public void Add(T delta, IEnumerable>? tags) + { + LastTags = tags; + Add(delta); + } + + public IEnumerable>? LastTags { get; private set; } + } + + private sealed class FakeUpDownCounter : IUpDownCounter + where T : struct + { + public T Value { get; private set; } + + public void Add(T delta, IEnumerable>? tags = null) + => Value = (T)(object)((int)(object)Value + (int)(object)delta); } private sealed class FakeHistogram : IHistogram @@ -454,7 +868,21 @@ private sealed class FakeHistogram : IHistogram { public T? LastRecordedValue { get; private set; } + public IEnumerable>? LastTags { get; private set; } + public void Record(T value) => LastRecordedValue = value; + + public void Record(T value, IEnumerable>? tags) + { + LastTags = tags; + LastRecordedValue = value; + } + + public void Reset() + { + LastRecordedValue = null; + LastTags = null; + } } }