Forward live output from testhost (#4352

playground/TestPlatform.Playground/Environment.cs

@@ -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"
     };
 
 }

src/Microsoft.TestPlatform.Client/DesignMode/DesignModeClient.cs

@@ -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;
 
@@ -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())
     {
     }
 
@@ -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>
@@ -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;
 
@@ -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)
     {

src/Microsoft.TestPlatform.CoreUtilities/Friends.cs

@@ -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")]
+

src/Microsoft.TestPlatform.TestHostProvider/Hosting/DefaultTestHostManager.cs

@@ -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.
@@ -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);
     };
 
@@ -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/>
@@ -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;
@@ -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.
@@ -519,7 +535,7 @@ private bool LaunchHost(TestProcessStartInfo testHostStartInfo, CancellationToke
                 testHostStartInfo.EnvironmentVariables,
                 ErrorReceivedCallback,
                 ExitCallBack,
-                null) as Process;
+                OutputReceivedCallback) as Process;
         }
         else
         {

src/Microsoft.TestPlatform.TestHostProvider/Hosting/DotnetTestHostManager.cs

@@ -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/>

src/Microsoft.TestPlatform.TestHostProvider/Hosting/TestHostManagerCallbacks.cs

@@ -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(

test/Microsoft.TestPlatform.Client.UnitTests/DesignMode/DesignModeClientTests.cs

@@ -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;
 
@@ -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);
     }
 
@@ -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);
@@ -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);
 
@@ -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);
 
@@ -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();
@@ -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)
         {
         }
 

test/Microsoft.TestPlatform.TestHostProvider.UnitTests/Hosting/TestHostManagerCallbacksTests.cs

@@ -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());
     }
@@ -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());
     }
@@ -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());
     }
@@ -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());
     }
@@ -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());
     }
@@ -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());
     }
@@ -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());
     }
@@ -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());
     }