Skip to content

Commit

Permalink
Forward live output from testhost (#4352
Browse files Browse the repository at this point in the history
* Forward live output from testhost

* Forward output for .NET Framework testhost.

When VSTEST_EXPERIMENTAL_FORWARD_OUTPUT_FEATURE is 1.

* revert playground

* Make exitCallback static again

* And another fix for static

* Fix fix
  • Loading branch information
nohwnd committed Mar 30, 2023
1 parent 2d656fe commit 135b4f2
Show file tree
Hide file tree
Showing 8 changed files with 86 additions and 24 deletions.
1 change: 1 addition & 0 deletions playground/TestPlatform.Playground/Environment.cs
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ internal class EnvironmentVariables
["VSTEST_RUNNER_DEBUG_ATTACHVS"] = "0",
["VSTEST_HOST_DEBUG_ATTACHVS"] = "0",
["VSTEST_DATACOLLECTOR_DEBUG_ATTACHVS"] = "0",
["VSTEST_EXPERIMENTAL_FORWARD_OUTPUT_FEATURE"] = "1"
};

}
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Logging;
using Microsoft.VisualStudio.TestPlatform.PlatformAbstractions;
using Microsoft.VisualStudio.TestPlatform.PlatformAbstractions.Interfaces;
using Microsoft.VisualStudio.TestPlatform.Utilities.Helpers.Interfaces;

using CommunicationUtilitiesResources = Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.Resources.Resources;

Expand Down Expand Up @@ -55,7 +56,7 @@ public class DesignModeClient : IDesignModeClient
/// Initializes a new instance of the <see cref="DesignModeClient"/> class.
/// </summary>
public DesignModeClient()
: this(new SocketCommunicationManager(), JsonDataSerializer.Instance, new PlatformEnvironment())
: this(new SocketCommunicationManager(), JsonDataSerializer.Instance, new PlatformEnvironment(), new EnvironmentVariableHelper())
{
}

Expand All @@ -71,13 +72,14 @@ public DesignModeClient()
/// <param name="platformEnvironment">
/// The platform Environment
/// </param>
internal DesignModeClient(ICommunicationManager communicationManager, IDataSerializer dataSerializer, IEnvironment platformEnvironment)
internal DesignModeClient(ICommunicationManager communicationManager, IDataSerializer dataSerializer, IEnvironment platformEnvironment, IEnvironmentVariableHelper environmentVariableHelper)
{
_communicationManager = communicationManager;
_dataSerializer = dataSerializer;
_platformEnvironment = platformEnvironment;
_testSessionMessageLogger = TestSessionMessageLogger.Instance;
_testSessionMessageLogger.TestRunMessage += TestRunMessageHandler;
_isForwardingOutput = environmentVariableHelper.GetEnvironmentVariable("VSTEST_EXPERIMENTAL_FORWARD_OUTPUT_FEATURE") == "1";
}

/// <summary>
Expand Down Expand Up @@ -446,7 +448,7 @@ public void TestRunMessageHandler(object? sender, TestRunMessageEventArgs e)
case TestMessageLevel.Informational:
EqtTrace.Info(e.Message);

if (EqtTrace.IsInfoEnabled)
if (_isForwardingOutput || EqtTrace.IsInfoEnabled)
SendTestMessage(e.Level, e.Message);
break;

Expand Down Expand Up @@ -653,6 +655,7 @@ void OnError(TestSessionEventsHandler eventsHandler, Exception? ex)
#region IDisposable Support

private bool _isDisposed; // To detect redundant calls
private bool _isForwardingOutput;

protected virtual void Dispose(bool disposing)
{
Expand Down
2 changes: 2 additions & 0 deletions src/Microsoft.TestPlatform.CoreUtilities/Friends.cs
Original file line number Diff line number Diff line change
Expand Up @@ -30,3 +30,5 @@
[assembly: InternalsVisibleTo("datacollector.UnitTests, PublicKey=002400000480000094000000060200000024000052534131000400000100010007d1fa57c4aed9f0a32e84aa0faefd0de9e8fd6aec8f87fb03766c834c99921eb23be79ad9d5dcc1dd9ad236132102900b723cf980957fc4e177108fc607774f29e8320e92ea05ece4e821c0a5efe8f1645c4c0c93c1ab99285d622caa652c1dfad63d745d6f2de5f17e5eaf0fc4963d261c8a12436518206dc093344d5ad293")]
[assembly: InternalsVisibleTo("testhost.UnitTests, PublicKey=002400000480000094000000060200000024000052534131000400000100010007d1fa57c4aed9f0a32e84aa0faefd0de9e8fd6aec8f87fb03766c834c99921eb23be79ad9d5dcc1dd9ad236132102900b723cf980957fc4e177108fc607774f29e8320e92ea05ece4e821c0a5efe8f1645c4c0c93c1ab99285d622caa652c1dfad63d745d6f2de5f17e5eaf0fc4963d261c8a12436518206dc093344d5ad293")]
[assembly: InternalsVisibleTo("vstest.ProgrammerTests, PublicKey=002400000480000094000000060200000024000052534131000400000100010007d1fa57c4aed9f0a32e84aa0faefd0de9e8fd6aec8f87fb03766c834c99921eb23be79ad9d5dcc1dd9ad236132102900b723cf980957fc4e177108fc607774f29e8320e92ea05ece4e821c0a5efe8f1645c4c0c93c1ab99285d622caa652c1dfad63d745d6f2de5f17e5eaf0fc4963d261c8a12436518206dc093344d5ad293")]
[assembly: InternalsVisibleTo("Microsoft.TestPlatform.Client.UnitTests, PublicKey=002400000480000094000000060200000024000052534131000400000100010007d1fa57c4aed9f0a32e84aa0faefd0de9e8fd6aec8f87fb03766c834c99921eb23be79ad9d5dcc1dd9ad236132102900b723cf980957fc4e177108fc607774f29e8320e92ea05ece4e821c0a5efe8f1645c4c0c93c1ab99285d622caa652c1dfad63d745d6f2de5f17e5eaf0fc4963d261c8a12436518206dc093344d5ad293")]

Original file line number Diff line number Diff line change
Expand Up @@ -65,8 +65,10 @@ public class DefaultTestHostManager : ITestRuntimeProvider2
private ITestHostLauncher? _customTestHostLauncher;
private Process? _testHostProcess;
private StringBuilder? _testHostProcessStdError;
private StringBuilder? _testHostProcessStdOut;
private IMessageLogger? _messageLogger;
private bool _hostExitedEventRaised;
private TestHostManagerCallbacks? _testhostManagerCallbacks;

/// <summary>
/// Initializes a new instance of the <see cref="DefaultTestHostManager"/> class.
Expand Down Expand Up @@ -123,6 +125,7 @@ internal DefaultTestHostManager(
private Action<object?> ExitCallBack => process =>
{
TPDebug.Assert(_testHostProcessStdError is not null, "LaunchTestHostAsync must have been called before ExitCallBack");
TPDebug.Assert(_testhostManagerCallbacks is not null, "Initialize must have been called before ExitCallBack");
TestHostManagerCallbacks.ExitCallBack(_processHelper, process, _testHostProcessStdError, OnHostExited);
};

Expand All @@ -132,7 +135,18 @@ internal DefaultTestHostManager(
private Action<object?, string?> ErrorReceivedCallback => (process, data) =>
{
TPDebug.Assert(_testHostProcessStdError is not null, "LaunchTestHostAsync must have been called before ErrorReceivedCallback");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, data);
TPDebug.Assert(_testhostManagerCallbacks is not null, "Initialize must have been called before ErrorReceivedCallback");
_testhostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, data);
};

/// <summary>
/// Gets callback to read from process error stream
/// </summary>
private Action<object?, string?> OutputReceivedCallback => (process, data) =>
{
TPDebug.Assert(_testHostProcessStdOut is not null, "LaunchTestHostAsync must have been called before OutputReceivedCallback");
TPDebug.Assert(_testhostManagerCallbacks is not null, "Initialize must have been called before OutputReceivedCallback");
_testhostManagerCallbacks.StandardOutputReceivedCallback(_testHostProcessStdOut, data);
};

/// <inheritdoc/>
Expand Down Expand Up @@ -357,6 +371,7 @@ public void Initialize(IMessageLogger? logger, string runsettingsXml)
var runConfiguration = XmlRunSettingsUtilities.GetRunConfigurationNode(runsettingsXml);

_messageLogger = logger;
_testhostManagerCallbacks = new TestHostManagerCallbacks(_environmentVariableHelper.GetEnvironmentVariable("VSTEST_EXPERIMENTAL_FORWARD_OUTPUT_FEATURE") == "1", logger);
_architecture = runConfiguration.TargetPlatform;
_targetFramework = runConfiguration.TargetFramework;
_testHostProcess = null;
Expand Down Expand Up @@ -498,6 +513,7 @@ private void OnHostExited(HostProviderEventArgs e)
private bool LaunchHost(TestProcessStartInfo testHostStartInfo, CancellationToken cancellationToken)
{
_testHostProcessStdError = new StringBuilder(0, CoreUtilities.Constants.StandardErrorMaxLength);
_testHostProcessStdOut = new StringBuilder(0, CoreUtilities.Constants.StandardErrorMaxLength);
EqtTrace.Verbose("Launching default test Host Process {0} with arguments {1}", testHostStartInfo.FileName, testHostStartInfo.Arguments);

// We launch the test host process here if we're on the normal test running workflow.
Expand All @@ -519,7 +535,7 @@ private bool LaunchHost(TestProcessStartInfo testHostStartInfo, CancellationToke
testHostStartInfo.EnvironmentVariables,
ErrorReceivedCallback,
ExitCallBack,
null) as Process;
OutputReceivedCallback) as Process;
}
else
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -169,7 +169,7 @@ private set
private Action<object?, string?> ErrorReceivedCallback => (process, data) =>
{
TPDebug.Assert(_testHostProcessStdError is not null, "_testHostProcessStdError is null");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, data);
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, data);
};

/// <inheritdoc/>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,21 +9,57 @@
using Microsoft.VisualStudio.TestPlatform.CoreUtilities.Extensions;
using Microsoft.VisualStudio.TestPlatform.ObjectModel;
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Host;
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Logging;
using Microsoft.VisualStudio.TestPlatform.PlatformAbstractions.Interfaces;

namespace Microsoft.TestPlatform.TestHostProvider.Hosting;

internal class TestHostManagerCallbacks
{
private const int E_HANDLE = unchecked((int)0x80070006);
private readonly bool _forwardOutput;
private readonly IMessageLogger? _messageLogger;

public static void ErrorReceivedCallback(StringBuilder testHostProcessStdError, string? data)
public TestHostManagerCallbacks(bool forwardOutput, IMessageLogger? logger)
{
if (forwardOutput)
{
string? but = null;
if (logger == null)
{
but = " But logger is null, so it won't forward any output.";
}
EqtTrace.Verbose($"TestHostManagerCallbacks.ctor: Experimental forwarding output is enabled.{but}");
}
else
{
EqtTrace.Verbose($"TestHostManagerCallbacks.ctor: Experimental forwarding output is disabled.");
}
_forwardOutput = forwardOutput;
_messageLogger = logger;
}

public void StandardOutputReceivedCallback(StringBuilder testHostProcessStdOut, string? data)
{
EqtTrace.Verbose("TestHostManagerCallbacks.StandardOutputReceivedCallback Test host standard output line: {0}", data);
testHostProcessStdOut.AppendSafeWithNewLine(data);
if (_forwardOutput && _messageLogger != null && !StringUtils.IsNullOrWhiteSpace(data))
{
_messageLogger.SendMessage(TestMessageLevel.Informational, data);
}
}

public void ErrorReceivedCallback(StringBuilder testHostProcessStdError, string? data)
{
// Log all standard error message because on too much data we ignore starting part.
// This is helpful in abnormal failure of testhost.
EqtTrace.Warning("TestHostManagerCallbacks.ErrorReceivedCallback Test host standard error line: {0}", data);

testHostProcessStdError.AppendSafeWithNewLine(data);
if (_forwardOutput && _messageLogger != null && !StringUtils.IsNullOrWhiteSpace(data))
{
_messageLogger.SendMessage(TestMessageLevel.Error, data);
}
}

public static void ExitCallBack(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Logging;
using Microsoft.VisualStudio.TestPlatform.PlatformAbstractions.Interfaces;
using Microsoft.VisualStudio.TestTools.UnitTesting;
using Microsoft.VisualStudio.TestPlatform.Utilities.Helpers.Interfaces;

using Moq;

Expand All @@ -40,14 +41,16 @@ public class DesignModeClientTests
private readonly DesignModeClient _designModeClient;
private readonly int _protocolVersion = 7;
private readonly AutoResetEvent _completeEvent;
private readonly Mock<IEnvironment> _mockPlatformEnvrironment;
private readonly Mock<IEnvironment> _mockPlatformEnvironment;
private readonly Mock<IEnvironmentVariableHelper> _mockEnvironmentVariableHelper;

public DesignModeClientTests()
{
_mockTestRequestManager = new Mock<ITestRequestManager>();
_mockCommunicationManager = new Mock<ICommunicationManager>();
_mockPlatformEnvrironment = new Mock<IEnvironment>();
_designModeClient = new DesignModeClient(_mockCommunicationManager.Object, JsonDataSerializer.Instance, _mockPlatformEnvrironment.Object);
_mockPlatformEnvironment = new Mock<IEnvironment>();
_mockEnvironmentVariableHelper = new Mock<IEnvironmentVariableHelper>();
_designModeClient = new DesignModeClient(_mockCommunicationManager.Object, JsonDataSerializer.Instance, _mockPlatformEnvironment.Object, _mockEnvironmentVariableHelper.Object);
_completeEvent = new AutoResetEvent(false);
}

Expand Down Expand Up @@ -283,7 +286,7 @@ public void DesignModeClientOnBadConnectionShouldStopServerAndThrowTimeoutExcept
[TestMethod]
public void DesignModeClientShouldStopCommunicationOnParentProcessExit()
{
_mockPlatformEnvrironment.Setup(pe => pe.Exit(It.IsAny<int>()));
_mockPlatformEnvironment.Setup(pe => pe.Exit(It.IsAny<int>()));
_designModeClient.HandleParentProcessExit();

_mockCommunicationManager.Verify(cm => cm.StopClient(), Times.Once);
Expand All @@ -292,7 +295,7 @@ public void DesignModeClientShouldStopCommunicationOnParentProcessExit()
[TestMethod]
public void DesignModeClientLaunchCustomHostMustReturnIfAckComes()
{
var testableDesignModeClient = new TestableDesignModeClient(_mockCommunicationManager.Object, JsonDataSerializer.Instance, _mockPlatformEnvrironment.Object);
var testableDesignModeClient = new TestableDesignModeClient(_mockCommunicationManager.Object, JsonDataSerializer.Instance, _mockPlatformEnvironment.Object, _mockEnvironmentVariableHelper.Object);

_mockCommunicationManager.Setup(cm => cm.WaitForServerConnection(It.IsAny<int>())).Returns(true);

Expand All @@ -312,7 +315,7 @@ public void DesignModeClientLaunchCustomHostMustReturnIfAckComes()
[ExpectedException(typeof(TestPlatformException))]
public void DesignModeClientLaunchCustomHostMustThrowIfInvalidAckComes()
{
var testableDesignModeClient = new TestableDesignModeClient(_mockCommunicationManager.Object, JsonDataSerializer.Instance, _mockPlatformEnvrironment.Object);
var testableDesignModeClient = new TestableDesignModeClient(_mockCommunicationManager.Object, JsonDataSerializer.Instance, _mockPlatformEnvironment.Object, _mockEnvironmentVariableHelper.Object);

_mockCommunicationManager.Setup(cm => cm.WaitForServerConnection(It.IsAny<int>())).Returns(true);

Expand All @@ -331,7 +334,7 @@ public void DesignModeClientLaunchCustomHostMustThrowIfInvalidAckComes()
[ExpectedException(typeof(TestPlatformException))]
public void DesignModeClientLaunchCustomHostMustThrowIfCancellationOccursBeforeHostLaunch()
{
var testableDesignModeClient = new TestableDesignModeClient(_mockCommunicationManager.Object, JsonDataSerializer.Instance, _mockPlatformEnvrironment.Object);
var testableDesignModeClient = new TestableDesignModeClient(_mockCommunicationManager.Object, JsonDataSerializer.Instance, _mockPlatformEnvironment.Object, _mockEnvironmentVariableHelper.Object);

var info = new TestProcessStartInfo();
var cancellationTokenSource = new CancellationTokenSource();
Expand Down Expand Up @@ -632,8 +635,9 @@ private class TestableDesignModeClient : DesignModeClient
internal TestableDesignModeClient(
ICommunicationManager communicationManager,
IDataSerializer dataSerializer,
IEnvironment platformEnvironment)
: base(communicationManager, dataSerializer, platformEnvironment)
IEnvironment platformEnvironment,
IEnvironmentVariableHelper environmentVariableHelper)
: base(communicationManager, dataSerializer, platformEnvironment, environmentVariableHelper)
{
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@ public TestHostManagerCallbacksTests()
public void ErrorReceivedCallbackShouldAppendNoDataOnNullDataReceived()
{
_testHostProcessStdError.Append("NoDataShouldAppend");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, null);
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, null);

Assert.AreEqual("NoDataShouldAppend", _testHostProcessStdError.ToString());
}
Expand All @@ -36,7 +36,7 @@ public void ErrorReceivedCallbackShouldAppendNoDataOnNullDataReceived()
public void ErrorReceivedCallbackShouldAppendNoDataOnEmptyDataReceived()
{
_testHostProcessStdError.Append("NoDataShouldAppend");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, string.Empty);
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, string.Empty);

Assert.AreEqual("NoDataShouldAppend", _testHostProcessStdError.ToString());
}
Expand All @@ -45,7 +45,7 @@ public void ErrorReceivedCallbackShouldAppendNoDataOnEmptyDataReceived()
public void ErrorReceivedCallbackShouldAppendWhiteSpaceString()
{
_testHostProcessStdError.Append("OldData");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, " ");
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, " ");

Assert.AreEqual("OldData " + Environment.NewLine, _testHostProcessStdError.ToString());
}
Expand All @@ -54,7 +54,7 @@ public void ErrorReceivedCallbackShouldAppendWhiteSpaceString()
public void ErrorReceivedCallbackShouldAppendGivenData()
{
_testHostProcessStdError.Append("NoDataShouldAppend");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, "new data");
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, "new data");

Assert.AreEqual("NoDataShouldAppendnew data" + Environment.NewLine, _testHostProcessStdError.ToString());
}
Expand All @@ -64,7 +64,7 @@ public void ErrorReceivedCallbackShouldNotAppendNewDataIfErrorMessageAlreadyReac
{
_testHostProcessStdError = new StringBuilder(0, 5);
_testHostProcessStdError.Append("12345");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, "678");
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, "678");

Assert.AreEqual("12345", _testHostProcessStdError.ToString());
}
Expand All @@ -74,7 +74,7 @@ public void ErrorReceivedCallbackShouldAppendSubStringOfDataIfErrorMessageReache
{
_testHostProcessStdError = new StringBuilder(0, 5);
_testHostProcessStdError.Append("1234");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, "5678");
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, "5678");

Assert.AreEqual("12345", _testHostProcessStdError.ToString());
}
Expand All @@ -84,7 +84,7 @@ public void ErrorReceivedCallbackShouldAppendEntireStringEvenItReachesToMaxLengt
{
_testHostProcessStdError = new StringBuilder(0, 5);
_testHostProcessStdError.Append("12");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, "3");
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, "3");

Assert.AreEqual("123" + Environment.NewLine, _testHostProcessStdError.ToString());
}
Expand All @@ -94,7 +94,7 @@ public void ErrorReceivedCallbackShouldAppendNewLineApproprioritlyWhenReachingMa
{
_testHostProcessStdError = new StringBuilder(0, 5);
_testHostProcessStdError.Append("123");
TestHostManagerCallbacks.ErrorReceivedCallback(_testHostProcessStdError, "4");
new TestHostManagerCallbacks(false, null).ErrorReceivedCallback(_testHostProcessStdError, "4");

Assert.AreEqual("1234" + Environment.NewLine.Substring(0, 1), _testHostProcessStdError.ToString());
}
Expand Down

0 comments on commit 135b4f2

Please sign in to comment.