Change SocketException to ServerNotAvailable + misc test fixes/logging (#5354)

This started out as a bit of test logging. Then the unrelated
GetProcessInfo test failed in CI so the change grew into a small product
fix + more test improvements.

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 logging to the DuplicateMetricNames test to improve diagnostics
when it hangs.
- 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
#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

---------

Co-authored-by: Mitchell Hwang <[email protected]>

Author: noahfalk

eng/InstallRuntimes.proj

@@ -113,7 +113,7 @@
   </Target>
 
 <!--
-    Writes the Debugger.Tests.Versions.txt file used by the SOS test harness
+    Writes the Debugger.Tests.Versions.txt file used by tests in this repo to determine which runtimes to test against
 -->
 
   <Target Name="WriteTestVersionManifest"

src/Microsoft.Diagnostics.NETCore.Client/DiagnosticsClient/DiagnosticsClientExceptions.cs

@@ -21,6 +21,7 @@ public UnsupportedProtocolException(string msg) : base(msg) { }
     public class ServerNotAvailableException : DiagnosticsClientException
     {
         public ServerNotAvailableException(string msg) : base(msg) { }
+        public ServerNotAvailableException(string msg, Exception exception) : base(msg, exception) { }
     }
 
     // When the runtime responded with an error

src/Microsoft.Diagnostics.NETCore.Client/DiagnosticsIpc/IpcTransport.cs

@@ -6,6 +6,7 @@
 using System.IO;
 using System.IO.Pipes;
 using System.Linq;
+using System.Net.Sockets;
 using System.Runtime.InteropServices;
 using System.Security.Principal;
 using System.Threading;
@@ -20,6 +21,7 @@ internal abstract class IpcEndpoint
         /// </summary>
         /// <param name="timeout">The amount of time to block attempting to connect</param>
         /// <returns>A stream used for writing and reading data to and from the target .NET process</returns>
+        /// <throws>ServerNotAvailableException</throws>
         public abstract Stream Connect(TimeSpan timeout);
 
         /// <summary>
@@ -29,6 +31,7 @@ internal abstract class IpcEndpoint
         /// <returns>
         /// A task that completes with a stream used for writing and reading data to and from the target .NET process.
         /// </returns>
+        /// <throws>ServerNotAvailableException</throws>
         public abstract Task<Stream> ConnectAsync(CancellationToken token);
 
         /// <summary>
@@ -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<Stream> 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);
             }
         }
     }

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:     <DebuggeeSourceRoot>/<DebuggeeName>/[<DebuggeeName>]
             // Binary Path:     <DebuggeeBuildRoot>/bin/<DebuggeeName>/<TargetConfiguration>/<BuildProjectFramework>

src/tests/CommonTestRunner/TestRunner.cs

@@ -49,6 +49,10 @@ public static async Task<TestRunner> 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();

src/tests/Microsoft.Diagnostics.Monitoring.EventPipe/EventCounterPipelineUnitTests.cs

@@ -59,15 +59,17 @@ private sealed class TestMetricsLogger : ICountersLogger
             private readonly List<ExpectedCounter> _expectedCounters = new();
             private Dictionary<ExpectedCounter, ICounterPayload> _metrics = new();
             private readonly TaskCompletionSource<object> _foundExpectedCountersSource;
+            private readonly ITestOutputHelper _output;
 
-            public TestMetricsLogger(IEnumerable<ExpectedCounter> expectedCounters, TaskCompletionSource<object> foundExpectedCountersSource)
+            public TestMetricsLogger(IEnumerable<ExpectedCounter> expectedCounters, TaskCompletionSource<object> foundExpectedCountersSource, ITestOutputHelper output)
             {
                 _foundExpectedCountersSource = foundExpectedCountersSource;
                 _expectedCounters = new(expectedCounters);
                 if (_expectedCounters.Count == 0)
                 {
                     foundExpectedCountersSource.SetResult(null);
                 }
+                _output = output;
             }
 
             public IEnumerable<ICounterPayload> 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<object> 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))
             {
@@ -169,7 +183,7 @@ public async Task TestDuplicateNameMetrics(TestConfiguration config)
                     new ExpectedCounter(providerName, counterName, "MeterTag=two","InstrumentTag=B"),
                 ];
             TaskCompletionSource<object> 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, testProcessTimeout: 3_000))
             {

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+1} 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));