NUnit tests failure not reported in test results file

[nehsharmMS]

Description

When NUnit test fails, it is shown in logs but failure is not getting reported in test results file (trx). Results node is missing in trx.

Steps to reproduce

Create Nunit test project and make a test to fail (e.g. use assert.Fail() ).

cmd to run :
vstest.console C:\Users\path_to_nunitdll\NUnitTestProject1.dll /logger:trx;logFileName="trx file path"

Version Info :
Nunit version : 3.10
NUnit test adapter Version used : 3.16 (latest)

Expected behavior

Test result should show test failure.

TRX Ouput:

<Results> <UnitTestResult executionId="909036b2-f21d-4046-b7af-866698432d49" testId="eea9dae7-e491-70bd-41d6-420224862c9d" testName="Test1" computerName="xyz" duration="00:00:00.0460000" startTime="2020-02-05T16:12:03.0000000+05:30" endTime="2020-02-05T16:12:03.0000000+05:30" testType="13cdc9d9-ddb5-4fa4-a97d-d965ccfc6d4b" outcome="Failed" testListId="8c84fa94-04c1-424b-9868-57a2d4851a1d" relativeResultsDirectory="909036b2-f21d-4046-b7af-866698432d49"> <Output> <ErrorInfo> <StackTrace> at Tests.Tests.Test1() in Test_project_path\NUnitTestProject1\UnitTest1.cs:line 15&#xD; </StackTrace> </ErrorInfo> </Output> </UnitTestResult> </Results>

Actual behavior

Results node is missing in trx hence not showing failed tests.

Environment

Operating system : Windows 10
vstest : Test Execution Command Line Tool Version 15.9.1

It appears issue with NUnit adapter latest version. When tried with old versions 3.13 or lower, trx is generated correctly with failed test results.

[singhsarab]

/cc: @AbhitejJohn

[ManishJayaswal]

@nohwnd - Is this a NUnit testadapter issue or an issue in vstest.console? If it is the former then should we open an issue in NUnit repo?

[thtp]

Can be reproduced with Assert.Fail() without parameters. Any non-empty message in a failure assertion fixes this issue (e.g. Assert.Fail("So sad")). Any conditional assertion also works fine (like Assetr.True(false)). So, most likely, issue is related to an empty message.

[nohwnd]

@ManishJayaswal don't know yet, I would suspect this is reponsibility of the adapter, but need to investigate it first.

[singhsarab]

AFAIK, this is an adapter issue and we should file a bug on Nunit. The older version 3.13 seems to be working as expected.

[AbhitejJohn]

Also if the trx logger is failing to add in a result for some reason, we'd probably want to add in some logs if they do not already exist.

[rprouse]

We've had this issue reported in NUnit as well, nunit/nunit3-vs-adapter#726

The failed tests appear correctly in the test window of Visual Studio, so the adapter is reporting the failed test correctly there.

CC @OsirisTerje

[nohwnd]

I saw this issue with a different adapter, the problem was that the reporting failed to generate while gerating the Results node, and while the errors is reported into the log, it does not bubble up to the caller, because the callbacks are invoked "safely".

[nohwnd]

commented in nunit/nunit3-vs-adapter#726 can't repro this on vstest.console 16.5 and 16.3.

[nohwnd]

The error occured because the error message produced by nunits Assert.Fail is null, and the initialization that would otherwise be done when setting the message was skipped. Fixed it so it initalizes when it sees null, so now there is no required order of setting the properties.

Reproduced like this, which allows me to easily see the execption in console:

dotnet test --logger trx --results-directory . -p:VSTestConsolePath="C:\Projects\vstest\artifacts\Debug\netcoreapp2.1\vstest.console.dll"

This is a fix in the VSTest console it will be shipped with VS 16.6, possibly preview 2. The fix won't be available by updating the test.sdk package.

Output with one added test that does Assert.AreEqual to make sure the null message is not our error:

  <Results>
    <UnitTestResult executionId="bcde2d4f-02b0-45b5-a6df-0a662b18a9b5" testId="0137b2fb-80ac-e41c-24d4-726c3c0e0520" testName="This_test_should_fail2" computerName="JAJARES-SURBOOK" duration="00:00:00.0310000" startTime="2020-03-18T11:44:26.0000000+01:00" endTime="2020-03-18T11:44:26.0000000+01:00" testType="13cdc9d9-ddb5-4fa4-a97d-d965ccfc6d4b" outcome="Failed" testListId="8c84fa94-04c1-424b-9868-57a2d4851a1d" relativeResultsDirectory="bcde2d4f-02b0-45b5-a6df-0a662b18a9b5">
      <Output>
        <ErrorInfo>
          <Message>  String lengths are both 1. Strings differ at index 0.&#xD;
  Expected: "a"&#xD;
  But was:  "b"&#xD;
  -----------^&#xD;
</Message>
          <StackTrace>   at nunit1.ExampleTest.This_test_should_fail2() in C:\Projects\temp\nunit1\UnitTest1.cs:line 17&#xD;
</StackTrace>
        </ErrorInfo>
      </Output>
    </UnitTestResult>
    <UnitTestResult executionId="0a270718-7381-4ec5-b853-eeb5daa8f1e4" testId="15a2ecc0-02b2-6a7f-d027-3074ab95741f" testName="This_test_should_pass" computerName="JAJARES-SURBOOK" duration="00:00:00.0010000" startTime="2020-03-18T11:44:26.0000000+01:00" endTime="2020-03-18T11:44:26.0000000+01:00" testType="13cdc9d9-ddb5-4fa4-a97d-d965ccfc6d4b" outcome="Passed" testListId="8c84fa94-04c1-424b-9868-57a2d4851a1d" relativeResultsDirectory="0a270718-7381-4ec5-b853-eeb5daa8f1e4" />
    <UnitTestResult executionId="173aabe0-099a-4863-8ef1-318283692935" testId="2a2e2546-9038-cc65-c034-21f198205f15" testName="This_test_should_fail" computerName="JAJARES-SURBOOK" duration="00:00:00.0890000" startTime="2020-03-18T11:44:26.0000000+01:00" endTime="2020-03-18T11:44:26.0000000+01:00" testType="13cdc9d9-ddb5-4fa4-a97d-d965ccfc6d4b" outcome="Failed" testListId="8c84fa94-04c1-424b-9868-57a2d4851a1d" relativeResultsDirectory="173aabe0-099a-4863-8ef1-318283692935">
      <Output>
        <ErrorInfo>
          <StackTrace>   at nunit1.ExampleTest.This_test_should_fail() in C:\Projects\temp\nunit1\UnitTest1.cs:line 11&#xD;
</StackTrace>
        </ErrorInfo>
      </Output>
    </UnitTestResult>
  </Results>