Some test failures not detected by Teamcity (no output from NUnit)

[oskarb]

Nunit console 3.10. Some test failures are reported in the output from each test as each test finishes but failures from other test cases are only reported in the summary at the end after all tests have finished. Parallel execution not used. Failures that are only reported in the summary causes Teamcity to not detect these failures.

The failures that are reported for each affected test case actually occurs in OneTimeSetup. The failures (for other test cases) that are only reported in the summary occur in regular [Setup], or in the test case itself.

What can cause this?

I have create a bug for Teamcity here, where I provided sample log output to show the problem: https://youtrack.jetbrains.com/issue/TW-61442

[CharliePoole]

Make sure you have the latest version of the teamcity extension for NUnit, 1.0.6.

[CharliePoole]

@ChrisMaddock It seems like it would be useful if the --list-extensions option gave the version of each extension present.

[oskarb]

Make sure you have the latest version of the teamcity extension for NUnit, 1.0.6.

Hmm, an interesting suggestion. I have the latest version of Teamcity (currently 2019.1.2 (build 66342)) and I have used its Tools menu to have TC itself download and install NUnit Console 3.10. I can verify that this in fact seems to not have installed the latest version of the teamcity extension, but instead uses 1.0.4.

[CharliePoole]

It's likely that 1.0.4 was the latest version available at the time 3.10 was released. When a new version of NUnit.Console is released, it will include the latest available extensions, but you can also update them yourself at any time.

[oskarb]

1.0.6 is in fact marked as being released 4 days before 3.10, and the NUnit console Nuget package depends on 1.0.6 but it seems to have not been updated in the zip-file. With the way it's setup in teamcity it doesn't really seem like I am supposed to have to fiddle with the extensions dll manually, but I guess I could try it just to see if it makes a difference. Not sure where to find it though - since there is no zip-file with the correct version included it seems the only way is to extract it from the nuget package.

[oskarb]

Actually it's even more messed up.

When I download this package from nuget: nunit.extension.teamcityeventlistener.1.0.6.nupkg

The file and product version of the teamcity-event-listener.dll: 1.0.4.0

It seems likely that the DLL contents is correct but the version number has not been updated properly. @NikolayPianikov

I've compared to the extension DLL from the console zip-file, and also to the extension DLL actually found in the teamcity agent. These binary files are exactly the same.

So what I can say for sure is that I am already using the teamcity-event-listener.dll from 1.0.6 of the nuget package, even though the file itself claims to be 1.0.4.

[oskarb]

@NikolayPianikov PR to correct version number in AssemblyInfo.cs (just a temporary solution to raise awareness): https://github.com/nunit/teamcity-event-listener/pull/69

[CharliePoole]

@ChrisMaddock Shouldn't this be transferred to the extension project?

[ChrisMaddock]

Yep, I agree. @oskarb - it looks like the console is reporting correctly here, and the issue is instead with the TeamCity Extension. I'll move this over now, @NikolayPianikov can always move it back if we have reason to believe otherwise.

[oskarb]

@NikolayPianikov Further experiments suggest that failures are not reported in Teamcity for tests where the standard output from the test doesn't end with a new line. In this case, the testFailed TC service message is tacked on to the end of the last line of test output and it seems this might make Teamcity miss them - though when looking at the build log in TC the service message is not visible there. So TC detects the service message to avoid showing it in the build log, but it fails to "act" upon the contents of the message?

TC docs state that:

To be processed by TeamCity, they need to be written to the standard output stream of the build, i.e. printed or echoed from a build step. It is recommended to output a single service message per line (i.e. divide messages with newline symbol(s))

So the docs does not really say that service message must be on a separate line. Only that it's recommended. In either case, I'm not outputting service messages - that is handled by this extension. It's brittle if I have to remember to design the tests to always end their output with a newline to avoid TC failing to detect the failures.

[NikolayPianikov]

@oskarb Could you share some simple solution to reproduce this issue, also please share actual and expected results for this solution.

[oskarb]

@NikolayPianikov

The expected result is that TC will report 6 failed tests for the following code snippet. The actual result is that only TestsWithErrorInOneTimeSetup_WithStdOut.Test1 is reported as failed in TC GUI. The buildlog will say in the NUnit summary that all of them failed. Tests are run using the NUnit TC build step.

If the four Console.Write are commented out, TC will correctly report 6 failures.

Notice that when the error occurs in OneTimeSetup, the error will be duplicated and reported separately for Test1 and Test2 in TC, if Console.Write call is commented out. This seems expected and good. If the write to console is present, TC will detect the failure for Test1 but not for Test2. I'm guessing the standard output from OneTimeSetup only occurs once, even if the exception is reported twice, and therefore it messes up the service message for one of the cases but not the other one.

using System;
using NUnit.Framework;

namespace FailuresNotDetectedByTeamcity
{
    [TestFixture]
    public class TestsWithErrorInOneTimeSetup_WithStdOut
    {
        private static int _execCount;

        [OneTimeSetUp]
        public void OneTimeSetup()
        {
            _execCount++;
            Console.Write("TEST OUTPUT WITH NO NEWLINE");
            throw new Exception($"Error in OneTimeSetup. Exec count: {_execCount}");
        }

        [Test]
        public void Test1()
        {
        }

        [Test]
        public void Test2()
        {
        }
    }

    [TestFixture]
    public class TestsWithErrorInSetup_WithStdOut
    {
        private static int _execCount;

        [SetUp]
        public void PerTestSetup()
        {
            _execCount++;
            Console.Write("TEST OUTPUT WITH NO NEWLINE");
            throw new Exception($"Error in PerTestSetup. Exec count: {_execCount}");
        }

        [Test]
        public void Test1()
        {
        }

        [Test]
        public void Test2()
        {
        }
    }

    [TestFixture]
    public class TestsWithErrorInTest_WithStdOut
    {
        private static int _execCount;

        [Test]
        public void Test1()
        {
            _execCount++;
            Console.Write("TEST OUTPUT WITH NO NEWLINE");
            throw new Exception($"Error in Test1. Exec count: {_execCount}");
        }

        [Test]
        public void Test2()
        {
            _execCount++;
            Console.Write("TEST OUTPUT WITH NO NEWLINE");
            throw new Exception($"Error in Test2. Exec count: {_execCount}");
        }
    }
}

[NikolayPianikov]

@oskarb Now the issue is reproducing. Thank you very much

[NikolayPianikov]

@oskarb If you have TeamCity 2019 installed try updating plugin

[oskarb]

@NikolayPianikov I've tried the patched plugin and both the test cases I posted above to reproduce and the actual currently failing test cases now seem to be reported correctly. Thanks!

[schuettecarsten]

Do you release the plugin update for the public?

[NikolayPianikov]

@schuettecarsten it will be available in the next patch release 2019.1.x and in the EAP 2019.2. Also you could install from the link above, it was built as a part of 2019.1.x and passed all tests