diff --git a/sdk/core/Azure.Core.TestFramework/README.md b/sdk/core/Azure.Core.TestFramework/README.md index 09e09e7a1f157..8da1b7de68b0f 100644 --- a/sdk/core/Azure.Core.TestFramework/README.md +++ b/sdk/core/Azure.Core.TestFramework/README.md @@ -380,6 +380,11 @@ The key integration points between the Test Framework and the Test Proxy are: - InstrumentClientOptions method of `RecordedTestBase` - calling this on your client options will set the [ClientOptions.Transport property](https://learn.microsoft.com/dotnet/api/azure.core.clientoptions.transport?view=azure-dotnet) to be [ProxyTransport](https://github.com/Azure/azure-sdk-for-net/blob/main/sdk/core/Azure.Core.TestFramework/src/ProxyTransport.cs) to your client options when in `Playback` or `Record` mode. The ProxyTransport will send all requests to the Test Proxy. - [TestProxy.cs](https://github.com/Azure/azure-sdk-for-net/blob/main/sdk/core/Azure.Core.TestFramework/src/TestProxy.cs) - This class is responsible for starting and stopping the Test Proxy process, as well as reporting any errors that occur in the Test Proxy process. The Test Proxy process is started automatically when running tests in `Record` or `Playback` mode, and is stopped automatically when the test run is complete. The Test Proxy process is shared between tests and test classes within a process. +#### Including Test Proxy Logs + +In order to enable Test Proxy logging, you can either set the `AZURE_ENABLE_TEST_PROXY_LOGGING` +environment variable or the `EnableTestProxyLogging` [runsetting](https://github.com/Azure/azure-sdk-for-net/blob/main/eng/nunit.runsettings) parameter to `true`. + ## Unit tests The Test Framework provides several classes that can help you write unit tests for your client library. Unit tests are helpful for scenarios that would be tricky to test with a recorded test, such as simulating certain error scenarios. diff --git a/sdk/core/Azure.Core.TestFramework/src/RecordedTestBase.cs b/sdk/core/Azure.Core.TestFramework/src/RecordedTestBase.cs index c3a7bd2160df6..bf9d6306c5647 100644 --- a/sdk/core/Azure.Core.TestFramework/src/RecordedTestBase.cs +++ b/sdk/core/Azure.Core.TestFramework/src/RecordedTestBase.cs @@ -458,7 +458,10 @@ public virtual async Task StopTestRecordingAsync() } } - _proxy?.CheckForErrors(); + if (_proxy != null) + { + await _proxy.CheckProxyOutputAsync(); + } } protected internal override object InstrumentClient(Type clientType, object client, IEnumerable preInterceptors) diff --git a/sdk/core/Azure.Core.TestFramework/src/TestEnvironment.cs b/sdk/core/Azure.Core.TestFramework/src/TestEnvironment.cs index 8d1d2c840c294..791d52a6eb23c 100644 --- a/sdk/core/Azure.Core.TestFramework/src/TestEnvironment.cs +++ b/sdk/core/Azure.Core.TestFramework/src/TestEnvironment.cs @@ -650,6 +650,22 @@ internal static bool EnableFiddler } } + /// + /// Determines whether to enable proxy logging beyond errors. + /// + internal static bool EnableProxyLogging + { + get + { + string switchString = TestContext.Parameters["EnableProxyLogging"] ?? + Environment.GetEnvironmentVariable("AZURE_ENABLE_PROXY_LOGGING"); + + bool.TryParse(switchString, out bool enableProxyLogging); + + return enableProxyLogging; + } + } + private void BootStrapTestResources() { lock (s_syncLock) diff --git a/sdk/core/Azure.Core.TestFramework/src/TestProxy.cs b/sdk/core/Azure.Core.TestFramework/src/TestProxy.cs index 4521342d35613..ee2fcb10a2f7a 100644 --- a/sdk/core/Azure.Core.TestFramework/src/TestProxy.cs +++ b/sdk/core/Azure.Core.TestFramework/src/TestProxy.cs @@ -9,6 +9,7 @@ using System.Reflection; using System.Runtime.InteropServices; using System.Text; +using System.Threading; using System.Threading.Tasks; using Azure.Core.Pipeline; using NUnit.Framework; @@ -38,6 +39,8 @@ public class TestProxy private readonly StringBuilder _errorBuffer = new(); private static readonly object _lock = new(); private static TestProxy _shared; + private readonly StringBuilder _output = new(); + private static readonly bool s_enableProxyLogging; static TestProxy() { @@ -56,6 +59,7 @@ static TestProxy() s_dotNetExe = Path.Combine(installDir, dotNetExeName); bool HasDotNetExe(string dotnetDir) => dotnetDir != null && File.Exists(Path.Combine(dotnetDir, dotNetExeName)); + s_enableProxyLogging = TestEnvironment.EnableProxyLogging; } private TestProxy(string proxyPath, bool debugMode = false) @@ -74,7 +78,9 @@ private TestProxy(string proxyPath, bool debugMode = false) EnvironmentVariables = { ["ASPNETCORE_URLS"] = $"http://{IpAddress}:0;https://{IpAddress}:0", + ["Logging__LogLevel__Azure.Sdk.Tools.TestProxy"] = s_enableProxyLogging ? "Debug" : "Error", ["Logging__LogLevel__Default"] = "Error", + ["Logging__LogLevel__Microsoft.AspNetCore"] = s_enableProxyLogging ? "Information" : "Error", ["Logging__LogLevel__Microsoft.Hosting.Lifetime"] = "Information", ["ASPNETCORE_Kestrel__Certificates__Default__Path"] = TestEnvironment.DevCertPath, ["ASPNETCORE_Kestrel__Certificates__Default__Password"] = TestEnvironment.DevCertPassword @@ -133,14 +139,24 @@ private TestProxy(string proxyPath, bool debugMode = false) var options = new TestProxyClientOptions(); Client = new TestProxyRestClient(new ClientDiagnostics(options), HttpPipelineBuilder.Build(options), new Uri($"http://{IpAddress}:{_proxyPortHttp}")); - // For some reason draining the standard output stream is necessary to keep the test-proxy process healthy. Otherwise requests - // start timing out. This only seems to happen when not specifying a port. _ = Task.Run( () => { while (!_testProxyProcess.HasExited && !_testProxyProcess.StandardOutput.EndOfStream) { - _testProxyProcess.StandardOutput.ReadLine(); + if (s_enableProxyLogging) + { + lock (_output) + { + _output.AppendLine(_testProxyProcess.StandardOutput.ReadLine()); + } + } + // For some reason draining the standard output stream is necessary to keep the test-proxy process healthy, even + // when we are not outputting logs. Otherwise, requests start timing out. + else + { + _testProxyProcess.StandardOutput.ReadLine(); + } } }); } @@ -204,7 +220,25 @@ private static bool TryParsePort(string output, string scheme, out int? port) return false; } - public void CheckForErrors() + public async Task CheckProxyOutputAsync() + { + if (s_enableProxyLogging) + { + // add a small delay to allow the log output for the just finished test to be collected into the _output StringBuilder + await Task.Delay(20); + + // lock to avoid any race conditions caused by appending to the StringBuilder while calling ToString + lock (_output) + { + TestContext.Out.WriteLine(_output.ToString()); + _output.Clear(); + } + } + + CheckForErrors(); + } + + private void CheckForErrors() { if (_errorBuffer.Length > 0) {