Async tests causes double failure messages

[OsirisTerje]

Given a test that is async, and which has both a Warn and an Assert statement, the failure output can be duplicated. Example is:

The code that produced this was:

/// <summary>
        /// YouKnow.TheAnswer returns 42
        /// </summary>
        /// <returns></returns>
        [Test]
        public async Task ThatTheAnswerIsFortyTwo()
        {
            Warn.If(YouKnow.TheAnswer, Is.Not.EqualTo(44));
            Assert.That(YouKnow.TheAnswer, Is.EqualTo(44));
        }

At first, this failure happened in a production case, and I had a hard time creating a repro for it. There are more factors that have to be in place. As can be seen, there are two exceptions that seem to be have been caught. It looks like it is an attribute added to the test class that is crucial for this to happen:

    [Timeout(50000)]
    public class Answers

Repro can be found here: https://github.com/nunit/nunit3-vs-adapter.issues/tree/master/nunit/Issue3694

This is coming from the framework, the output from the engine/framework is:

<test-case id='0-1001' name='Test1' fullname='Issue3694.Tests.Test1' methodname='Test1' classname='Issue3694.Tests' runstate='Runnable' seed='1982432749' result='Failed' label='Error' start-time='2020-12-20 20:56:22Z' end-time='2020-12-20 20:56:22Z' duration='0.054763' asserts='2' parentId='0-1000'>
   <failure>
      <message><![CDATA[System.AggregateException : One or more errors occurred. (Multiple failures or warnings in test:
  1)   Expected: not not equal to 44
  But was:  42

  2)   Expected: 44
  But was:  42

)
  ----> NUnit.Framework.AssertionException : Multiple failures or warnings in test:
  1)   Expected: not not equal to 44
  But was:  42

  2)   Expected: 44
  But was:  42

]]></message>
      <stack-trace><![CDATA[   at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout)
   at NUnit.Framework.Internal.Commands.TimeoutCommand.Execute(TestExecutionContext context)
--AssertionException
   at NUnit.Framework.Assert.ReportFailure(String message)
   at NUnit.Framework.Assert.ReportFailure(ConstraintResult result, String message, Object[] args)
   at NUnit.Framework.Assert.That[TActual](TActual actual, IResolveConstraint expression, String message, Object[] args)
   at NUnit.Framework.Assert.That[TActual](TActual actual, IResolveConstraint expression)
   at Issue3694.Tests.Test1() in d:\repos\NUnit\nunit3-vs-adapter.issues\nunit\Issue3694\UnitTest1.cs:line 15
   at NUnit.Framework.Internal.TaskAwaitAdapter.GenericAdapter`1.GetResult()
   at NUnit.Framework.Internal.AsyncToSyncAdapter.Await(Func`1 invoke)
   at NUnit.Framework.Internal.Commands.TestMethodCommand.RunTestMethod(TestExecutionContext context)
   at NUnit.Framework.Internal.Commands.TestMethodCommand.Execute(TestExecutionContext context)
   at NUnit.Framework.Internal.Commands.TimeoutCommand.<>c__DisplayClass2_0.<Execute>b__0()
   at System.Threading.Tasks.Task`1.InnerInvoke()
   at System.Threading.Tasks.Task.<>c.<.cctor>b__277_0(Object obj)
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)]]></stack-trace>
   </failure>
   <assertions>
      <assertion result='Warning'>
         <message><![CDATA[  Expected: not not equal to 44
  But was:  42
]]></message>
         <stack-trace><![CDATA[   at Issue3694.Tests.Test1() in d:\repos\NUnit\nunit3-vs-adapter.issues\nunit\Issue3694\UnitTest1.cs:line 14
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Issue3694.Tests.Test1()
]]></stack-trace>
      </assertion>
      <assertion result='Failed'>
         <message><![CDATA[  Expected: 44
  But was:  42
]]></message>
         <stack-trace><![CDATA[   at Issue3694.Tests.Test1() in d:\repos\NUnit\nunit3-vs-adapter.issues\nunit\Issue3694\UnitTest1.cs:line 15
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Issue3694.Tests.Test1()
]]></stack-trace>
      </assertion>
   </assertions>
</test-case>

[mikkelbu]

@OsirisTerje I saw from the repo project that this is targeting .Net 5 and using NUnit framework version 3.12. This sounds related to #3282 which will be part of the coming release. Does it also repo when using one of the latest pre-release builds from https://www.myget.org/feed/nunit/package/nuget/NUnit ?

[OsirisTerje]

It works in 3.13.0-dbg (which I got from Rob), so I'll close this as fixed in 3.13 :-)

[OsirisTerje]

That said: The output "Expected: not not equal to 44" is perhaps not the best way of an expression :-)

[mikkelbu]

I don't think I've ever looked at the code for Warn.If, but I wonder if we could "normalise" the expression (which would also help if the user had written Assert.That(YouKnow.TheAnswer, Is.Not.Not.EqualTo(44)) :) ).

[OsirisTerje]

Would have been cool :-) But the first time I have seen something like that.