Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Enable Test Proxy logging in Test Framework #37994

Merged
merged 13 commits into from
Aug 3, 2023
8 changes: 8 additions & 0 deletions sdk/core/Azure.Core.TestFramework/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -354,6 +354,8 @@ This attribute, when used with `RecordedTestBase`-derived test fixtures`, will m

### Debugging Test Proxy

#### Debug Mode

The Test Proxy and Test Framework include detailed error messages for test failures. However, there will always be times where it is necessary to debug to figure out what is going wrong, particularly if the issue actually exists in the Test Framework or Test Proxy code rather than in your test or client library.

In order to enable debug mode, set the `UseLocalDebugProxy` property to true in your class that inherits from `RecordedTestBase`:
Expand All @@ -380,6 +382,12 @@ 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 Debug level logs

It is also possible to observe Debug logs from the Test Proxy by setting the environment
variable `Logging__LogLevel__Azure.Sdk.Tools.TestProxy` to `Debug`. This can be done locally, or
when queueing a build in Azure DevOps by adding a variable to the run.

## 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.
Expand Down
5 changes: 4 additions & 1 deletion sdk/core/Azure.Core.TestFramework/src/RecordedTestBase.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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<IInterceptor> preInterceptors)
Expand Down
26 changes: 23 additions & 3 deletions sdk/core/Azure.Core.TestFramework/src/TestProxy.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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 const string TestProxyLogLevelEnvironmentVariable = "Logging__LogLevel__Azure.Sdk.Tools.TestProxy";

static TestProxy()
{
Expand All @@ -64,6 +67,8 @@ private TestProxy(string proxyPath, bool debugMode = false)

debugMode |= environmentDebugMode;

string proxyLogLevel = Environment.GetEnvironmentVariable(TestProxyLogLevelEnvironmentVariable);

ProcessStartInfo testProxyProcessInfo = new ProcessStartInfo(
s_dotNetExe,
$"\"{proxyPath}\" --storage-location=\"{TestEnvironment.RepositoryRoot}\"")
Expand All @@ -74,7 +79,9 @@ private TestProxy(string proxyPath, bool debugMode = false)
EnvironmentVariables =
{
["ASPNETCORE_URLS"] = $"http://{IpAddress}:0;https://{IpAddress}:0",
[TestProxyLogLevelEnvironmentVariable] = proxyLogLevel ?? "Information",
["Logging__LogLevel__Default"] = "Error",
["Logging__LogLevel__Microsoft.AspNetCore"] = "Information",
JoshLove-msft marked this conversation as resolved.
Show resolved Hide resolved
["Logging__LogLevel__Microsoft.Hosting.Lifetime"] = "Information",
["ASPNETCORE_Kestrel__Certificates__Default__Path"] = TestEnvironment.DevCertPath,
["ASPNETCORE_Kestrel__Certificates__Default__Password"] = TestEnvironment.DevCertPassword
Expand Down Expand Up @@ -123,7 +130,7 @@ private TestProxy(string proxyPath, bool debugMode = false)

if (_proxyPortHttp == null || _proxyPortHttps == null)
{
CheckForErrors();
_ = CheckProxyOutputAsync();
// if no errors, fallback to this exception
throw new InvalidOperationException("Failed to start the test proxy. One or both of the ports was not populated." + Environment.NewLine +
$"http: {_proxyPortHttp}" + Environment.NewLine +
Expand All @@ -140,7 +147,10 @@ private TestProxy(string proxyPath, bool debugMode = false)
{
while (!_testProxyProcess.HasExited && !_testProxyProcess.StandardOutput.EndOfStream)
{
_testProxyProcess.StandardOutput.ReadLine();
lock (_output)
{
_output.AppendLine(_testProxyProcess.StandardOutput.ReadLine());
}
}
});
}
Expand Down Expand Up @@ -204,8 +214,18 @@ private static bool TryParsePort(string output, string scheme, out int? port)
return false;
}

public void CheckForErrors()
public async Task CheckProxyOutputAsync()
{
// 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);
JoshLove-msft marked this conversation as resolved.
Show resolved Hide resolved

// lock to avoid any race conditions caused by appending to the StringBuilder while calling ToString
lock (_output)
{
TestContext.Out.WriteLine(_output.ToString());
_output.Clear();
}

if (_errorBuffer.Length > 0)
{
var error = _errorBuffer.ToString();
Expand Down