From f16b2e527be88ba7b10285ce7657071f354ea969 Mon Sep 17 00:00:00 2001 From: Noah Falk Date: Tue, 18 Mar 2025 00:11:51 -0700 Subject: [PATCH 1/3] Add some logging the DuplicateMetricName test Trying to diagnose why the test isn't completing and the issue isn't reproing locally. --- .../EventCounterPipelineUnitTests.cs | 22 +++++++++++++++---- 1 file changed, 18 insertions(+), 4 deletions(-) diff --git a/src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs b/src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs index 72852297c3..64cc0d9a14 100644 --- a/src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs +++ b/src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs @@ -59,8 +59,9 @@ private sealed class TestMetricsLogger : ICountersLogger private readonly List _expectedCounters = new(); private Dictionary _metrics = new(); private readonly TaskCompletionSource _foundExpectedCountersSource; + private readonly ITestOutputHelper _output; - public TestMetricsLogger(IEnumerable expectedCounters, TaskCompletionSource foundExpectedCountersSource) + public TestMetricsLogger(IEnumerable expectedCounters, TaskCompletionSource foundExpectedCountersSource, ITestOutputHelper output) { _foundExpectedCountersSource = foundExpectedCountersSource; _expectedCounters = new(expectedCounters); @@ -68,6 +69,7 @@ public TestMetricsLogger(IEnumerable expectedCounters, TaskComp { foundExpectedCountersSource.SetResult(null); } + _output = output; } public IEnumerable Metrics => _metrics.Values; @@ -90,17 +92,29 @@ public void Log(ICounterPayload payload) ExpectedCounter expectedCounter = _expectedCounters.Find(c => c.MatchesCounterMetadata(payload.CounterMetadata)); if(expectedCounter != null) { + _expectedCounters.Remove(expectedCounter); _metrics.Add(expectedCounter, payload); + + _output.WriteLine($"Found expected counter: {expectedCounter.ProviderName}/{expectedCounter.CounterName}. Counters remaining={_expectedCounters.Count}"); // Complete the task source if the last expected key was removed. if (_expectedCounters.Count == 0) { + _output.WriteLine($"All expected counters have been received. Signaling pipeline can exit."); _foundExpectedCountersSource.TrySetResult(null); } } + else + { + _output.WriteLine($"Received additional counter event: {payload.CounterMetadata.ProviderName}/{payload.CounterMetadata.CounterName}"); + } } - public Task PipelineStarted(CancellationToken token) => Task.CompletedTask; + public Task PipelineStarted(CancellationToken token) + { + _output.WriteLine("Counters pipeline is running. Waiting to receive expected counters from tracee."); + return Task.CompletedTask; + } public Task PipelineStopped(CancellationToken token) => Task.CompletedTask; } @@ -113,7 +127,7 @@ public async Task TestCounterEventPipeline(TestConfiguration config) TaskCompletionSource foundExpectedCountersSource = new(TaskCreationOptions.RunContinuationsAsynchronously); - TestMetricsLogger logger = new(expectedCounters.Select(name => new ExpectedCounter(expectedProvider, name)), foundExpectedCountersSource); + TestMetricsLogger logger = new(expectedCounters.Select(name => new ExpectedCounter(expectedProvider, name)), foundExpectedCountersSource, _output); await using (TestRunner testRunner = await PipelineTestUtilities.StartProcess(config, "CounterRemoteTest", _output)) { @@ -165,7 +179,7 @@ public async Task TestDuplicateNameMetrics(TestConfiguration config) new ExpectedCounter(providerName, counterName, "MeterTag=two","InstrumentTag=B"), ]; TaskCompletionSource foundExpectedCountersSource = new(TaskCreationOptions.RunContinuationsAsynchronously); - TestMetricsLogger logger = new(expectedCounters, foundExpectedCountersSource); + TestMetricsLogger logger = new(expectedCounters, foundExpectedCountersSource, _output); await using (TestRunner testRunner = await PipelineTestUtilities.StartProcess(config, "DuplicateNameMetrics", _output)) { From 04f16c0890ae5c95463d8b8a3faef0757ffa868a Mon Sep 17 00:00:00 2001 From: Noah Falk Date: Tue, 18 Mar 2025 22:52:27 -0700 Subject: [PATCH 2/3] Use ServerNotAvailableException + test fixes Product changes: - Connecting to the IPC channel might fail when the runtime is starting up, shutting down, or is overloaded. If so the socket.Connect() call is going to throw a SocketException. In order to avoid having callers to DiagnosticClient APIs understand all the implrementation details and have to use catch clauses for a wide variety of different exceptions we now catch this exception and rethrow it wrapped as a ServerNotAvailableException. Test changes: - Add retries to the GetProcessInfo requests that are running while the target process is starting up. There is no guarantee the runtime is listening to the socket at this point and connection requests may be refused. This may resolve one cause of flakiness noted in https://github.com/dotnet/diagnostics/issues/2760. The issue also shows a 'ReadPastEndOfStream' problem that is not addressed by this fix. - Add verification that the ExePath returned by DebuggeeCompiler actually exists on disk. This catches some build/config issues in the test setup more eagerly. - Add verification that the BuildProjectFramework and TargetConfiguration used by SdkPrebuiltDebuggeeCompiler are populated. This catches some specific test configuration errors more eagerly. - Tweaked some out-of-date comments --- eng/InstallRuntimes.proj | 2 +- .../DiagnosticsClientExceptions.cs | 1 + .../DiagnosticsIpc/IpcTransport.cs | 114 ++++++++++-------- .../SdkPrebuiltDebuggeeCompiler.cs | 9 ++ src/tests/CommonTestRunner/TestRunner.cs | 4 + .../GetProcessInfoTests.cs | 17 ++- 6 files changed, 97 insertions(+), 50 deletions(-) diff --git a/eng/InstallRuntimes.proj b/eng/InstallRuntimes.proj index e7615549eb..289d7152ee 100644 --- a/eng/InstallRuntimes.proj +++ b/eng/InstallRuntimes.proj @@ -98,7 +98,7 @@ /// The amount of time to block attempting to connect /// A stream used for writing and reading data to and from the target .NET process + /// ServerNotAvailableException public abstract Stream Connect(TimeSpan timeout); /// @@ -29,6 +31,7 @@ internal abstract class IpcEndpoint /// /// A task that completes with a stream used for writing and reading data to and from the target .NET process. /// + /// ServerNotAvailableException public abstract Task ConnectAsync(CancellationToken token); /// @@ -51,66 +54,81 @@ internal static class IpcEndpointHelper { public static Stream Connect(IpcEndpointConfig config, TimeSpan timeout) { - if (config.Transport == IpcEndpointConfig.TransportType.NamedPipe) - { - NamedPipeClientStream namedPipe = new( - ".", - config.Address, - PipeDirection.InOut, - PipeOptions.None, - TokenImpersonationLevel.Impersonation); - namedPipe.Connect((int)timeout.TotalMilliseconds); - return namedPipe; - } - else if (config.Transport == IpcEndpointConfig.TransportType.UnixDomainSocket) + try { - IpcUnixDomainSocket socket = new(); - socket.Connect(new IpcUnixDomainSocketEndPoint(config.Address), timeout); - return new ExposedSocketNetworkStream(socket, ownsSocket: true); - } + if (config.Transport == IpcEndpointConfig.TransportType.NamedPipe) + { + NamedPipeClientStream namedPipe = new( + ".", + config.Address, + PipeDirection.InOut, + PipeOptions.None, + TokenImpersonationLevel.Impersonation); + namedPipe.Connect((int)timeout.TotalMilliseconds); + return namedPipe; + } + else if (config.Transport == IpcEndpointConfig.TransportType.UnixDomainSocket) + { + IpcUnixDomainSocket socket = new(); + socket.Connect(new IpcUnixDomainSocketEndPoint(config.Address), timeout); + return new ExposedSocketNetworkStream(socket, ownsSocket: true); + } #if DIAGNOSTICS_RUNTIME - else if (config.Transport == IpcEndpointConfig.TransportType.TcpSocket) - { - var tcpClient = new TcpClient (); - var endPoint = new IpcTcpSocketEndPoint(config.Address); - tcpClient.Connect(endPoint.EndPoint); - return tcpClient.GetStream(); - } + else if (config.Transport == IpcEndpointConfig.TransportType.TcpSocket) + { + var tcpClient = new TcpClient (); + var endPoint = new IpcTcpSocketEndPoint(config.Address); + tcpClient.Connect(endPoint.EndPoint); + return tcpClient.GetStream(); + } #endif - else + else + { + throw new ArgumentException($"Unsupported IpcEndpointConfig transport type {config.Transport}"); + } + + } + catch (SocketException ex) { - throw new ArgumentException($"Unsupported IpcEndpointConfig transport type {config.Transport}"); + throw new ServerNotAvailableException($"Unable to connect to the server. {ex.Message}", ex); } } public static async Task ConnectAsync(IpcEndpointConfig config, CancellationToken token) { - if (config.Transport == IpcEndpointConfig.TransportType.NamedPipe) - { - NamedPipeClientStream namedPipe = new( - ".", - config.Address, - PipeDirection.InOut, - PipeOptions.Asynchronous, - TokenImpersonationLevel.Impersonation); - - // Pass non-infinite timeout in order to cause internal connection algorithm - // to check the CancellationToken periodically. Otherwise, if the named pipe - // is waited using WaitNamedPipe with an infinite timeout, then the - // CancellationToken cannot be observed. - await namedPipe.ConnectAsync(int.MaxValue, token).ConfigureAwait(false); - - return namedPipe; - } - else if (config.Transport == IpcEndpointConfig.TransportType.UnixDomainSocket) + try { - IpcUnixDomainSocket socket = new(); - await socket.ConnectAsync(new IpcUnixDomainSocketEndPoint(config.Address), token).ConfigureAwait(false); - return new ExposedSocketNetworkStream(socket, ownsSocket: true); + if (config.Transport == IpcEndpointConfig.TransportType.NamedPipe) + { + NamedPipeClientStream namedPipe = new( + ".", + config.Address, + PipeDirection.InOut, + PipeOptions.Asynchronous, + TokenImpersonationLevel.Impersonation); + + // Pass non-infinite timeout in order to cause internal connection algorithm + // to check the CancellationToken periodically. Otherwise, if the named pipe + // is waited using WaitNamedPipe with an infinite timeout, then the + // CancellationToken cannot be observed. + await namedPipe.ConnectAsync(int.MaxValue, token).ConfigureAwait(false); + + return namedPipe; + } + else if (config.Transport == IpcEndpointConfig.TransportType.UnixDomainSocket) + { + IpcUnixDomainSocket socket = new(); + await socket.ConnectAsync(new IpcUnixDomainSocketEndPoint(config.Address), token).ConfigureAwait(false); + return new ExposedSocketNetworkStream(socket, ownsSocket: true); + } + else + { + throw new ArgumentException($"Unsupported IpcEndpointConfig transport type {config.Transport}"); + } } - else + catch (SocketException ex) { - throw new ArgumentException($"Unsupported IpcEndpointConfig transport type {config.Transport}"); + throw new ServerNotAvailableException($"Unable to connect to the server. {ex.Message}", ex); } } } diff --git a/src/Microsoft.Diagnostics.TestHelpers/SdkPrebuiltDebuggeeCompiler.cs b/src/Microsoft.Diagnostics.TestHelpers/SdkPrebuiltDebuggeeCompiler.cs index d397dd809e..ebc4105d43 100644 --- a/src/Microsoft.Diagnostics.TestHelpers/SdkPrebuiltDebuggeeCompiler.cs +++ b/src/Microsoft.Diagnostics.TestHelpers/SdkPrebuiltDebuggeeCompiler.cs @@ -15,6 +15,15 @@ public class SdkPrebuiltDebuggeeCompiler : IDebuggeeCompiler public SdkPrebuiltDebuggeeCompiler(TestConfiguration config, string debuggeeName) { + if (string.IsNullOrEmpty(config.TargetConfiguration)) + { + throw new System.ArgumentException("TargetConfiguration must be set in the TestConfiguration"); + } + if (string.IsNullOrEmpty(config.BuildProjectFramework)) + { + throw new System.ArgumentException("BuildProjectFramework must be set in the TestConfiguration"); + } + // The layout is how the current .NET Core SDK layouts the binaries out: // Source Path: //[] // Binary Path: /bin/// diff --git a/src/tests/CommonTestRunner/TestRunner.cs b/src/tests/CommonTestRunner/TestRunner.cs index a552385a6a..bffa8ed642 100644 --- a/src/tests/CommonTestRunner/TestRunner.cs +++ b/src/tests/CommonTestRunner/TestRunner.cs @@ -49,6 +49,10 @@ public static async Task Create(TestConfiguration config, ITestOutpu // Get the full debuggee launch command line (includes the host if required) string exePath = debuggeeConfig.BinaryExePath; + if (!File.Exists(exePath)) + { + throw new FileNotFoundException($"Expected to find target executable at {exePath} but it didn't exist. Perhaps the path was improperly configured or a build/deployment error caused the file to be missing?"); + } string pipeName = null; StringBuilder arguments = new(); diff --git a/src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs b/src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs index 961ee8123e..8542380531 100644 --- a/src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs +++ b/src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs @@ -74,7 +74,22 @@ private async Task BasicProcessInfoTestCore(TestConfiguration config, bool useAs ProcessInfo processInfoBeforeResume = null; if (suspend) { - processInfoBeforeResume = await clientShim.GetProcessInfo(); + // when the process is just starting up, the IPC channel may not be ready yet. We need to be prepared for the connection attempt to fail. + // If 100 retries over 10 seconds fail then we'll go ahead and fail the test. + const int retryCount = 100; + for (int i = 0; i < retryCount; i++) + { + try + { + processInfoBeforeResume = await clientShim.GetProcessInfo(); + break; + } + catch (ServerNotAvailableException) when (i < retryCount-1) + { + _output.WriteLine($"Failed to connect to the IPC channel as the process is starting up. Attempt {i} of {retryCount}. Waiting 0.1 seconds, then retrying."); + await Task.Delay(100); + } + } ValidateProcessInfo(runner.Pid, processInfoBeforeResume); Assert.True((config.RuntimeFrameworkVersionMajor < 8) == string.IsNullOrEmpty(processInfoBeforeResume.ManagedEntrypointAssemblyName)); From 0d3f37aadb9003a6e071aa44c430c92a25023ca1 Mon Sep 17 00:00:00 2001 From: Noah Falk Date: Mon, 14 Jul 2025 14:14:08 -0700 Subject: [PATCH 3/3] Update src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs Co-authored-by: Mitchell Hwang <16830051+mdh1418@users.noreply.github.com> --- .../Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs b/src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs index 8542380531..7f7181bc47 100644 --- a/src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs +++ b/src/tests/Microsoft.Diagnostics.NETCore.Client/GetProcessInfoTests.cs @@ -86,7 +86,7 @@ private async Task BasicProcessInfoTestCore(TestConfiguration config, bool useAs } catch (ServerNotAvailableException) when (i < retryCount-1) { - _output.WriteLine($"Failed to connect to the IPC channel as the process is starting up. Attempt {i} of {retryCount}. Waiting 0.1 seconds, then retrying."); + _output.WriteLine($"Failed to connect to the IPC channel as the process is starting up. Attempt {i+1} of {retryCount}. Waiting 0.1 seconds, then retrying."); await Task.Delay(100); } }