Skip to content

Commit

Permalink
Fix console output problem, dotnet test appeared to hang (#102)
Browse files Browse the repository at this point in the history
* Fix console output problem

* remove accidental commit of TestAdapter reference

* Add XML-Doc

* Bump the TCP client buffer size to 10 Kib
  • Loading branch information
Arkatufus committed Nov 2, 2021
1 parent bf04a68 commit bebe537
Show file tree
Hide file tree
Showing 7 changed files with 333 additions and 54 deletions.
Original file line number Diff line number Diff line change
@@ -0,0 +1,217 @@
// -----------------------------------------------------------------------
// <copyright file="XUnitSinkAdapter.cs" company="Akka.NET Project">
// Copyright (C) 2009-2021 Lightbend Inc. <http://www.lightbend.com>
// Copyright (C) 2013-2021 .NET Foundation <https://github.com/akkadotnet/akka.net>
// </copyright>
// -----------------------------------------------------------------------

using System;
using System.Linq;
using Akka.Actor;
using Akka.Event;
using Akka.MultiNode.TestAdapter.Internal.Reporting;
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Adapter;
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Logging;
using Microsoft.VisualStudio.TestPlatform.Utilities;

namespace Akka.MultiNode.TestAdapter.Internal.Sinks
{
/// <summary>
/// <see cref="MessageSinkActor"/> implementation that redirects all logs to the <see cref="IFrameworkHandle"/> VSTest adapter.
///
/// Has no persistence capabilities. Can optionally use a <see cref="TestRunCoordinator"/> to provide total "end of test" reporting.
/// </summary>
public class FrameworkHandleMessageSinkActor: TestCoordinatorEnabledMessageSink
{
private readonly IFrameworkHandle _frameworkHandle;
private readonly ConsoleOutput _consoleOutput;

public FrameworkHandleMessageSinkActor(
bool useTestCoordinator,
IFrameworkHandle frameworkHandle)
: base(useTestCoordinator)
{
_frameworkHandle = frameworkHandle;
_consoleOutput = ConsoleOutput.Instance;
}

#region Message handling

protected override void AdditionalReceives()
{
Receive<FactData>(data => ReceiveFactData(data));
}

protected override void ReceiveFactData(FactData data)
{
PrintSpecRunResults(data);
}

private void PrintSpecRunResults(FactData data)
{
WriteSpecMessage($"Results for {data.FactName}");
WriteSpecMessage($"Start time: {new DateTime(data.StartTime, DateTimeKind.Utc)}");
foreach (var node in data.NodeFacts)
{
WriteSpecMessage(
$" --> Node {node.Value.NodeIndex}:{node.Value.NodeRole} : {(node.Value.Passed.GetValueOrDefault(false) ? "PASS" : "FAIL")} [{node.Value.Elapsed} elapsed]");
}
WriteSpecMessage(
$"End time: {new DateTime(data.EndTime.GetValueOrDefault(DateTime.UtcNow.Ticks), DateTimeKind.Utc)}");
WriteSpecMessage(
$"FINAL RESULT: {(data.Passed.GetValueOrDefault(false) ? "PASS" : "FAIL")} after {data.Elapsed}.");

//If we had a failure
if (data.Passed.GetValueOrDefault(false) == false)
{
WriteSpecMessage("Failure messages by Node");
foreach (var node in data.NodeFacts)
{
if (node.Value.Passed.GetValueOrDefault(false) == false)
{
WriteSpecMessage($"<----------- BEGIN NODE {node.Key}:{node.Value.NodeRole} ----------->");
foreach (var resultMessage in node.Value.ResultMessages)
{
WriteSpecMessage($" --> {resultMessage.Message}");
}
if (node.Value.ResultMessages == null || node.Value.ResultMessages.Count == 0)
WriteSpecMessage("[received no messages - SILENT FAILURE].");
WriteSpecMessage($"<----------- END NODE {node.Key}:{node.Value.NodeRole} ----------->");
}
}
}
}

protected override void HandleNodeSpecFail(NodeCompletedSpecWithFail nodeFail)
{
WriteSpecFail(nodeFail.NodeIndex, nodeFail.NodeRole, nodeFail.Message);

base.HandleNodeSpecFail(nodeFail);
}

protected override void HandleTestRunEnd(EndTestRun endTestRun)
{
WriteSpecMessage("Test run complete.");

base.HandleTestRunEnd(endTestRun);
}

protected override void HandleTestRunTree(TestRunTree tree)
{
var passedSpecs = tree.Specs.Count(x => x.Passed.GetValueOrDefault(false));
WriteSpecMessage(
$"Test run completed in [{tree.Elapsed}] with {passedSpecs}/{tree.Specs.Count()} specs passed.");
foreach (var factData in tree.Specs)
{
PrintSpecRunResults(factData);
}
}

protected override void HandleNewSpec(BeginNewSpec newSpec)
{
WriteSpecMessage($"Beginning spec {newSpec.ClassName}.{newSpec.MethodName} on {newSpec.Nodes.Count} nodes");

base.HandleNewSpec(newSpec);
}

protected override void HandleEndSpec(EndSpec endSpec)
{
WriteSpecMessage("Spec completed.");

base.HandleEndSpec(endSpec);
}

protected override void HandleNodeMessageFragment(LogMessageFragmentForNode logMessage)
{
WriteNodeMessage(logMessage);

base.HandleNodeMessageFragment(logMessage);
}

protected override void HandleRunnerMessage(LogMessageForTestRunner node)
{
WriteRunnerMessage(node);

base.HandleRunnerMessage(node);
}

protected override void HandleNodeSpecPass(NodeCompletedSpecWithSuccess nodeSuccess)
{
WriteSpecPass(nodeSuccess.NodeIndex, nodeSuccess.NodeRole, nodeSuccess.Message);

base.HandleNodeSpecPass(nodeSuccess);
}

#endregion

#region FrameworkHandle output methods

/// <summary>
/// Used to print a spec status message (spec starting, finishing, failed, etc...)
/// </summary>
private void WriteSpecMessage(string message)
{
_frameworkHandle.SendMessage(
TestMessageLevel.Informational,
$"[RUNNER][{DateTime.UtcNow.ToShortTimeString()}]: {message}");
}

private void WriteSpecPass(int nodeIndex, string nodeRole, string message)
{
_frameworkHandle.SendMessage(
TestMessageLevel.Informational,
$"[NODE{nodeIndex}:{nodeRole}][{DateTime.UtcNow.ToShortTimeString()}]: SPEC PASSED: {message}");
}

private void WriteSpecFail(int nodeIndex, string nodeRole, string message)
{
_frameworkHandle.SendMessage(
TestMessageLevel.Error,
$"[NODE{nodeIndex}:{nodeRole}][{DateTime.UtcNow.ToShortTimeString()}]: SPEC FAILED: {message}");
}

private void WriteRunnerMessage(LogMessageForTestRunner nodeMessage)
{
switch (nodeMessage.Level)
{
case LogLevel.WarningLevel:
_frameworkHandle.SendMessage(TestMessageLevel.Warning, nodeMessage.ToString());
break;
case LogLevel.ErrorLevel:
_frameworkHandle.SendMessage(TestMessageLevel.Error, nodeMessage.ToString());
break;
case LogLevel.DebugLevel:
case LogLevel.InfoLevel:
default:
_frameworkHandle.SendMessage(TestMessageLevel.Informational, nodeMessage.ToString());
break;
}
}

private void WriteNodeMessage(LogMessageFragmentForNode nodeMessage)
{
_frameworkHandle.SendMessage(TestMessageLevel.Informational, nodeMessage.ToString());
}

#endregion
}

/// <summary>
/// <see cref="IMessageSink"/> implementation that redirects outputs to <see cref="IFrameworkHandle"/>.
/// </summary>
public class FrameworkHandleMessageSink : MessageSink
{
private readonly IFrameworkHandle _frameworkHandle;

public FrameworkHandleMessageSink(IFrameworkHandle frameworkHandle)
: base(Props.Create(() => new FrameworkHandleMessageSinkActor(true, frameworkHandle)))
{
_frameworkHandle = frameworkHandle;
}

protected override void HandleUnknownMessageType(string message)
{
_frameworkHandle.SendMessage(TestMessageLevel.Warning, $"Unknown message: {message}");
}
}
}
73 changes: 41 additions & 32 deletions src/Akka.MultiNode.TestAdapter/Internal/Sinks/MessageSink.cs
Original file line number Diff line number Diff line change
Expand Up @@ -112,15 +112,15 @@ public static MultiNodeTestRunnerMessageType DetermineMessageType(string message
var matchRunnerLog = RunnerLogMessageRegex.Match(messageStr);
if (matchRunnerLog.Success) return MultiNodeTestRunnerMessageType.RunnerLogMessage;

var matchFailureReason = NodeFailureReasonRegex.Match(messageStr);
if(matchFailureReason.Success) return MultiNodeTestRunnerMessageType.NodeFailureException;

var matchStatus = NodePassStatusRegex.Match(messageStr);
if (matchStatus.Success)
{
return matchStatus.Groups["status"].Value.Equals(NodePassed) ? MultiNodeTestRunnerMessageType.NodePassMessage : MultiNodeTestRunnerMessageType.NodeFailMessage;
}

var matchFailureReason = NodeFailureReasonRegex.Match(messageStr);
if(matchFailureReason.Success) return MultiNodeTestRunnerMessageType.NodeFailureException;

var nodeLogFragmentStatus = NodeLogFragmentRegex.Match(messageStr);
if(nodeLogFragmentStatus.Success) return MultiNodeTestRunnerMessageType.NodeLogFragment;

Expand Down Expand Up @@ -239,36 +239,45 @@ public void LogRunnerMessage(string message, string logSource, LogLevel level)

public void Offer(string messageStr)
{
var messageType = DetermineMessageType(messageStr);
if (messageType == MultiNodeTestRunnerMessageType.Unknown)
{
HandleUnknownMessageType(messageStr);
return;
}

if (messageType == MultiNodeTestRunnerMessageType.RunnerLogMessage)
{
LogMessageForTestRunner runnerLog;
if (!TryParseLogMessage(messageStr, out runnerLog)) throw new InvalidOperationException("could not parse test runner log message: " + messageStr);
MessageSinkActorRef.Tell(runnerLog);
}
else if (messageType == MultiNodeTestRunnerMessageType.NodePassMessage)
{
NodeCompletedSpecWithSuccess nodePass;
if (!TryParseSuccessMessage(messageStr, out nodePass)) throw new InvalidOperationException("could not parse node spec pass message: " + messageStr);
MessageSinkActorRef.Tell(nodePass);
}
else if (messageType == MultiNodeTestRunnerMessageType.NodeFailMessage)
{
NodeCompletedSpecWithFail nodeFail;
if (!TryParseFailureMessage(messageStr, out nodeFail)) throw new InvalidOperationException("could not parse node spec fail message: " + messageStr);
MessageSinkActorRef.Tell(nodeFail);
}
else if (messageType == MultiNodeTestRunnerMessageType.NodeFailureException)
switch (DetermineMessageType(messageStr))
{
NodeCompletedSpecWithFail nodeFail;
if (!TryParseFailureExceptionMessage(messageStr, out nodeFail)) throw new InvalidOperationException("could not parse node spec failure + EXCEPTION message: " + messageStr);
MessageSinkActorRef.Tell(nodeFail);
case MultiNodeTestRunnerMessageType.Unknown:
HandleUnknownMessageType(messageStr);
return;

case MultiNodeTestRunnerMessageType.RunnerLogMessage:
if (!TryParseLogMessage(messageStr, out LogMessageForTestRunner runnerLog))
throw new InvalidOperationException("could not parse test runner log message: " + messageStr);
MessageSinkActorRef.Tell(runnerLog);
return;

case MultiNodeTestRunnerMessageType.NodePassMessage:
if (!TryParseSuccessMessage(messageStr, out var nodePass))
throw new InvalidOperationException("could not parse node spec pass message: " + messageStr);
MessageSinkActorRef.Tell(nodePass);
return;

case MultiNodeTestRunnerMessageType.NodeFailMessage:
if (!TryParseFailureMessage(messageStr, out var nodeFail))
throw new InvalidOperationException("could not parse node spec fail message: " + messageStr);
MessageSinkActorRef.Tell(nodeFail);
return;

case MultiNodeTestRunnerMessageType.NodeFailureException:
if (!TryParseFailureExceptionMessage(messageStr, out var nodeFailEx))
throw new InvalidOperationException("could not parse node spec failure + EXCEPTION message: " + messageStr);
MessageSinkActorRef.Tell(nodeFailEx);
return;

case MultiNodeTestRunnerMessageType.NodeLogFragment:
case MultiNodeTestRunnerMessageType.NodeLogMessage:
if (!TryParseLogMessage(messageStr, out LogMessageFragmentForNode fragmentLog))
throw new InvalidOperationException("could not parse test runner log message: " + messageStr);
MessageSinkActorRef.Tell(fragmentLog);
break;

default:
throw new ArgumentOutOfRangeException();
}
}

Expand Down
18 changes: 16 additions & 2 deletions src/Akka.MultiNode.TestAdapter/Internal/Sinks/SinkCoordinator.cs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
// </copyright>
//-----------------------------------------------------------------------

using System;
using System.Collections.Generic;
using System.Linq;
using System.Reflection;
Expand Down Expand Up @@ -85,13 +86,15 @@ public RecommendedExitCode(int code)
protected int TotalReceiveClosedConfirmations = 0;
protected int ReceivedSinkCloseConfirmations = 0;

protected ILoggingAdapter Log { get; }

/// <summary>
/// Leave the console message sink enabled by default
/// </summary>
public SinkCoordinator()
: this(new[] { new ConsoleMessageSink() })
{

Log = Context.GetLogger();
}

public SinkCoordinator(IEnumerable<MessageSink> defaultSinks)
Expand Down Expand Up @@ -192,7 +195,18 @@ private void PublishToChildren(RunnerMessage message)
private void PublishToChildren(string message)
{
foreach (var sink in Sinks)
sink.Offer(message);
{
try
{
sink.Offer(message);
}
catch (Exception e)
{
// This message might never make it to console, due to the way dotnet test is being set,
// but at least this catch would not cause the SinkCoordinator to die mid test because of an exception
Log.Error(e, "Sink {0} failed to process message {1}: {2}", sink.GetType(), message, e.Message);
}
}
}

#endregion
Expand Down
4 changes: 2 additions & 2 deletions src/Akka.MultiNode.TestAdapter/MultiNodeTestAdapter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -147,7 +147,7 @@ private static MultiNodeTestRunnerOptions BuildOptions(IRunContext runContext, I
var runSettings = runContext.RunSettings;
if (runSettings == null)
{
return MultiNodeTestRunnerOptions.Default;
return MultiNodeTestRunnerOptions.Default.WithFrameworkHandle(frameworkHandle);
}

var runConfiguration = XmlRunSettingsUtilities.GetRunConfigurationNode(runSettings.SettingsXml);
Expand All @@ -158,7 +158,7 @@ private static MultiNodeTestRunnerOptions BuildOptions(IRunContext runContext, I
if (runConfiguration.ResultsDirectorySet)
options = options.WithOutputDirectory(runConfiguration.ResultsDirectory);

return options;
return options.WithFrameworkHandle(frameworkHandle);
}

private static MultiNodeTestRunner CreateRunner(
Expand Down

0 comments on commit bebe537

Please sign in to comment.