// 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.Extensions.Diagnostics.Resources; using Microsoft.Testing.Extensions.HangDump.Serializers; using Microsoft.Testing.Platform.CommandLine; using Microsoft.Testing.Platform.Extensions; using Microsoft.Testing.Platform.Extensions.Messages; using Microsoft.Testing.Platform.Extensions.TestHost; using Microsoft.Testing.Platform.Helpers; using Microsoft.Testing.Platform.IPC; using Microsoft.Testing.Platform.IPC.Models; using Microsoft.Testing.Platform.IPC.Serializers; using Microsoft.Testing.Platform.Logging; using Microsoft.Testing.Platform.Services; namespace Microsoft.Testing.Extensions.Diagnostics; [UnsupportedOSPlatform("browser")] [UnsupportedOSPlatform("wasi")] internal sealed class HangDumpActivityIndicator : IDataConsumer, ITestSessionLifetimeHandler, #if NETCOREAPP IAsyncDisposable, #endif IDisposable { private readonly ICommandLineOptions _commandLineOptions; private readonly IEnvironment _environment; private readonly ITask _task; private readonly IClock _clock; private readonly ILogger _logger; private readonly NamedPipeClient? _namedPipeClient; private readonly bool _traceLevelEnabled; private readonly ConcurrentDictionary _testsCurrentExecutionState = new(); private bool _exitSignalActivityIndicatorAsync; private NamedPipeServer? _singleConnectionNamedPipeServer; private PipeNameDescription? _pipeNameDescription; public HangDumpActivityIndicator( ICommandLineOptions commandLineOptions, IEnvironment environment, ITask task, ILoggerFactory loggerFactory, IClock clock) { _logger = loggerFactory.CreateLogger(); _traceLevelEnabled = _logger.IsEnabled(LogLevel.Trace); _commandLineOptions = commandLineOptions; _environment = environment; _task = task; _clock = clock; if (HangDumpOptions.IsEnabled(_commandLineOptions)) { string namedPipeName = _environment.GetEnvironmentVariable(HangDumpEnvironmentVariableProvider.PipeNameEnvironmentVariableName) ?? throw new InvalidOperationException($"Expected {HangDumpEnvironmentVariableProvider.PipeNameEnvironmentVariableName} environment variable set."); _namedPipeClient = new NamedPipeClient(namedPipeName, _environment); _namedPipeClient.RegisterSerializer(new VoidResponseSerializer(), typeof(VoidResponse)); _namedPipeClient.RegisterSerializer(new ConsumerPipeNameRequestSerializer(), typeof(ConsumerPipeNameRequest)); _namedPipeClient.RegisterSerializer(new ActivitySignalRequestSerializer(), typeof(ActivitySignalRequest)); } } public Type[] DataTypesConsumed => [typeof(TestNodeUpdateMessage)]; public string Uid => nameof(HangDumpActivityIndicator); public string Version => ExtensionVersion.DefaultSemVer; public string DisplayName => ExtensionResources.HangDumpExtensionDisplayName; public string Description => ExtensionResources.HangDumpExtensionDescription; public Task IsEnabledAsync() => Task.FromResult(HangDumpOptions.IsEnabled(_commandLineOptions)); public async Task OnTestSessionStartingAsync(ITestSessionContext testSessionContext) { CancellationToken cancellationToken = testSessionContext.CancellationToken; ApplicationStateGuard.Ensure(_namedPipeClient is not null); cancellationToken.ThrowIfCancellationRequested(); try { // Connect to the named pipe server await _logger.LogTraceAsync($"Connecting to the process lifetime handler {_namedPipeClient.PipeName}").ConfigureAwait(false); await _namedPipeClient.ConnectAsync(cancellationToken).TimeoutAfterAsync(TimeoutHelper.DefaultHangTimeSpanTimeout, cancellationToken).ConfigureAwait(false); await _logger.LogTraceAsync("Connected to the process lifetime handler").ConfigureAwait(false); // Setup the server channel with the testhost controller _pipeNameDescription = NamedPipeServer.GetPipeName(Guid.NewGuid().ToString("N")); await _logger.LogTraceAsync($"Hang dump pipe name: '{_pipeNameDescription.Name}'").ConfigureAwait(false); _singleConnectionNamedPipeServer = new(_pipeNameDescription, CallbackAsync, _environment, _logger, _task, cancellationToken); _singleConnectionNamedPipeServer.RegisterSerializer(new GetInProgressTestsResponseSerializer(), typeof(GetInProgressTestsResponse)); _singleConnectionNamedPipeServer.RegisterSerializer(new GetInProgressTestsRequestSerializer(), typeof(GetInProgressTestsRequest)); _singleConnectionNamedPipeServer.RegisterSerializer(new VoidResponseSerializer(), typeof(VoidResponse)); await _logger.LogTraceAsync($"Send consumer pipe name to the test controller '{_pipeNameDescription.Name}'").ConfigureAwait(false); await _namedPipeClient.RequestReplyAsync(new ConsumerPipeNameRequest(_pipeNameDescription.Name), cancellationToken) .TimeoutAfterAsync(TimeoutHelper.DefaultHangTimeSpanTimeout, cancellationToken).ConfigureAwait(false); // Wait the connection from the testhost controller await _singleConnectionNamedPipeServer.WaitConnectionAsync(cancellationToken).TimeoutAfterAsync(TimeoutHelper.DefaultHangTimeSpanTimeout, cancellationToken).ConfigureAwait(false); await _logger.LogTraceAsync("Test host controller connected").ConfigureAwait(false); } catch (OperationCanceledException ex) when (ex.CancellationToken == cancellationToken) { // Do nothing, we're stopping } } private async Task CallbackAsync(IRequest request) { if (request is GetInProgressTestsRequest) { await _logger.LogDebugAsync($"Received '{nameof(GetInProgressTestsRequest)}'").ConfigureAwait(false); _exitSignalActivityIndicatorAsync = true; return new GetInProgressTestsResponse([.. _testsCurrentExecutionState.Select(x => (x.Value.Name, (int)_clock.UtcNow.Subtract(x.Value.StartTime).TotalSeconds))]); } else { throw new ArgumentOutOfRangeException(string.Format(CultureInfo.InvariantCulture, ExtensionResources.HangDumpUnsupportedRequestTypeErrorMessage, request.GetType().FullName)); } } public async Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationToken cancellationToken) { cancellationToken.ThrowIfCancellationRequested(); if (value is not TestNodeUpdateMessage nodeChangedMessage) { return; } TestNodeStateProperty? state = nodeChangedMessage.TestNode.Properties.SingleOrDefault(); bool executionCompleted = nodeChangedMessage.TestNode.Properties.Any(); if (state is InProgressTestNodeStateProperty) { if (_traceLevelEnabled) { // Stryker disable once Boolean: continuation scheduling does not change the trace diagnostic. await _logger.LogTraceAsync($"New in-progress test '{nodeChangedMessage.TestNode.DisplayName}'").ConfigureAwait(false); } _testsCurrentExecutionState.TryAdd(nodeChangedMessage.TestNode.Uid, (nodeChangedMessage.TestNode.DisplayName, typeof(InProgressTestNodeStateProperty), _clock.UtcNow)); } #pragma warning disable CS0618, MTP0001 // Type or member is obsolete else if ((executionCompleted || state is PassedTestNodeStateProperty or ErrorTestNodeStateProperty or CancelledTestNodeStateProperty #pragma warning restore CS0618, MTP0001 // Type or member is obsolete or FailedTestNodeStateProperty or TimeoutTestNodeStateProperty or SkippedTestNodeStateProperty) // A test framework that retries in-process reports a terminal update per attempt but only one // in-progress update for the test. Dropping it from the in-progress set on a superseded attempt would // leave the test untracked while its next attempt is still running, so a hang during that attempt // would not be attributed to it in the hang dump's in-progress list. && !nodeChangedMessage.TestNode.IsSupersededRetryAttempt() && _testsCurrentExecutionState.TryRemove(nodeChangedMessage.TestNode.Uid, out (string Name, Type Type, DateTimeOffset StartTime) record) && _traceLevelEnabled) { // Stryker disable once Boolean: continuation scheduling does not change the trace diagnostic. await _logger.LogTraceAsync($"Test removed from in-progress list '{record.Name}' after '{_clock.UtcNow.Subtract(record.StartTime)}', total in-progress '{_testsCurrentExecutionState.Count}'").ConfigureAwait(false); } // Optimization, we're interested in test progression and eventually in the discovery progression if (state is not InProgressTestNodeStateProperty) { if (_traceLevelEnabled) { // Stryker disable once Boolean: continuation scheduling does not change the trace diagnostic. await _logger.LogTraceAsync($"Signal for action node {nodeChangedMessage.TestNode.DisplayName} - '{state}'. _exitSignalActivityIndicatorAsync: {_exitSignalActivityIndicatorAsync}").ConfigureAwait(false); } // Signal the activity. if (!_exitSignalActivityIndicatorAsync) { ApplicationStateGuard.Ensure(_namedPipeClient is not null); await _namedPipeClient.RequestReplyAsync(ActivitySignalRequest.Instance, cancellationToken).ConfigureAwait(false); if (_traceLevelEnabled) { await _logger.LogTraceAsync($"Activity signal sent.").ConfigureAwait(false); } } } } public Task OnTestSessionFinishingAsync(ITestSessionContext testSessionContext) => Task.CompletedTask; #if NETCOREAPP public ValueTask DisposeAsync() { _namedPipeClient?.Dispose(); return ValueTask.CompletedTask; } #endif public void Dispose() => _namedPipeClient?.Dispose(); }