Vstest: Integration of XUnit and TeamCity is broken

[NikolayPianikov]

Description

XUnit has built-in integration with TeamCity

Steps to reproduce

• Create xunit test project dotnet new xunit
• Set environment variable SET TEAMCITY_PROJECT_NAME to some value to simulate running under TeamCity, for instance: SET TEAMCITY_PROJECT_NAME=my
• Run tests using some verbosity level: dotnet test --verbosity Minimal or dotnet test --verbosity quiet

Expected behavior

You should find messages like ##teamcity[testStarted in stdOut
for all verbosity levels

Actual behavior

There are no any messages like ##teamcity[testStarted in stdOut

Environment

dotnet --version:
2.1.200
2.1.300-rc1-008673

[dtretyakov]

@smadala, @martincostello please take a look at this problem. In SDK 2.1.104 all works fine, since 2.1.200 we're able to reproduce it.

[dtretyakov]

@mayankbansal018, any progress on it?

[mayankbansal018]

@singhsarab , can you please take a look at this issue

[dtretyakov]

@singhsarab, @smadala, we're getting more and more tickets about this breaking change. Please arrange the priority of this issue.

[singhsarab]

@dtretyakov This is by design as verbosity minimal and quiet, the expectation is that no informational logs should be shown for these levels.
We fixed the behavior as part of https://github.com/Microsoft/vstest/pull/1396

Recommendation is use normal or detailed verbosity for full detailed logs.

[zone117x]

Using normal or verbose logging is not working. I can see the additional log messages, but nothing that is picked up by teamcity.

[martincostello]

Passing --verbosity=normal as an argument to dotnet test outputs test results to TeamCity (2017.1.4) as it did in previous versions of the SDK when using 2.1.300 of the .NET Core SDK.

[NikolayPianikov]

@singhsarab Verbosity level should not make any influence on CI integration. We should take in account that not only people run tests (they can use some IDE for this), vice versa in the most cases a CI runs tests via a command line.

Now

• in the quiet mode there are now any integration at all
• in the minimal (default) mode the integration works only for failed tests

It seems to be a breaking change, the very confusing behavior, thus the only thing we can recommend: "to not use these modes" by large red letters.

[martincostello]

To illustrate this change, here is a screenshot from my application's CI build in TeamCity.

Build 1.0.1105 uses --verbosity=normal - the test results are shown.
Build 1.0.1104 uses the previous behaviour of just running dotnet test without any explicit verbosity arguments - no test results are shown at all.

From the perspective of a TeamCity user, #1396 was a breaking change.

[zone117x]

@martincostello Your work around is not working for me. Are you using anything else in your setup? Any preview nuget packages?

The verbosity change is not a work around to the problem, unless I'm missing something.
Here is an example "dotnet new xunit" project with the TeamCity.VSTest.TestAdapter package and couple example tests added: https://github.com/zone117x/DebugTeamCityTestReporting

Created a new build configuration with the dotnet CLI runner using test command and verbosity set to normal. Attached build logs with: attempt 1) first run, attempt 2) run with /nodeReuse:false parameter, attempt 3) running on a Windows build agent with latest stable dotnet SDK/runtime.

DebugTestReporting_Tests_attempt-1.log
DebugTestReporting_Tests_attempt-2_disable-nodereuse.log
DebugTestReporting_Tests_attempt-3_win-build_agent.log

Screenshot of the build config:

[martincostello]

@zone117x I'm not using the built-in .NET Core TeamCity runner - I'm using a vanilla PowerShell step that calls into my own .ps1 that invokes dotnet test itself.

[zone117x]

Just created a custom script build step with dotnet test DebugTeamCityTestReporting.csproj --verbosity Normal /nodeReuse:false
Doesn't work.

[martincostello]

What about if your put an equals between the parameter name and value like in my example above? Otherwise, I’m not sure why it would work for me but not for you.

[zone117x]

Wow. I tried --verbosity normal instead of --verbosity Normal and it worked..
dotnet test should probably not require that to be case sensitive, or at least output a warning about an invalid command line parameter.

@NikolayPianikov In the mean time, Teamcity .NET build agent needs to use lowercase variables for the verbosity option.

[NikolayPianikov]

@zone117x @martincostello thank you for info, done. Try updating to new version

[akatz0813]

@nikolayPianikov which version specifically?

[NikolayPianikov]

@akatz0813 from this page for appropriate TeamCity version

[martincostello]

FYI I've found that using this argument instead means that test verbosity is increased to that required but _build_ verbosity isn't, so then the behaviour is actually like-for-like:

--logger:"console;verbosity=normal"

[singhsarab]

@NikolayPianikov May I go ahead and close the issue?

[NikolayPianikov]

@singhsarab we just found some workaround for (https://github.com/JetBrains/teamcity-dotnet-plugin/issues/127), but I hoped it is temporary solution. Also some related issues (like https://github.com/JetBrains/TeamCity.VSTest.TestAdapter#visual-studio-test-platform) have only partially workaround.
Are you not planing to fix? It is your choice, but please note that it is quite important for any CI systems.

[singhsarab]

@NikolayPianikov Unfortunate that this came as a breaking change for you guys, but glad that you have a solution in place now. As I mentioned earlier, this change in behavior is actually a fix we made to ensure we are consistent. The current behavior is by design.

The solution you guys have now seems appropriate for specification.
This change is not a take back as such, because logger verbosity can be configured for detailed logging.
Please let me know if you disagree. Thanks.

[joaopgrassi]

@martincostello I just bumped into the same issue! Saw your other tickets as well. I just upgraded from 2.1.101 to 2.1.300 and was getting no tests on TeamCity as well. I agree that this is a breaking change and I don't like having to pass more arguments than before. It works passing --logger:"console;verbosity=normal" but.. was better before IMHO.

[smadala]

@NikolayPianikov @dtretyakov Can you please consider printing messages to console in teamcity logger?

[NikolayPianikov]

@smadala Yes but the test information will be duplicated depending on verbosity level

[smadala]

@NikolayPianikov Can we add ##teamcity prefix only in logger itself rather than in xunit adapter?

From https://github.com/Microsoft/vstest/issues/1606 There are various issues and PRs floating around that set the console logger's verbosity to...

Console logger behavior has been changing almost in every release as per different requirements of vstest.console.exe and dotnet test scenario.

We really don't want to change the behavior of vstest console logger until it is very much required.

I think teamcity CI integration can be achieved without depending on console logger behavior.

[NikolayPianikov]

TeamCity has a lot of clients and we treat them with respect. Many of them have already established CI processes and we must not allow any things to make their lives more difficult. When developers creating their products they are using VS Studio or Rider or something else and I know few of them who are really running tests from the command line after that. Of course console tools should be comfortable for users in the command line but we should not forget about an automation of build/test/deploy process. Thus CI services are no less important customers.

Yes we thought about using pipes to reliable send an information about tests to CI. But this scenarion is not so transparent. In the case of stdOut customers can control and trace information exchange between all parts of CI and to solve a lot of issues independently. For pipes all this is much more difficult.

Another thing what we could do is to the remove direct TeamCity support in xunit, because of this is not working reliably now. In this case TeamCity and xunit will avoid conflicts with information about tests. From my point of view your team and xunit team could discuss it.

[smadala]

@NikolayPianikov

TeamCity has a lot of clients and we treat them with respect. Many of them have already established CI processes and we must not allow any things to make their lives more difficult.

We all are on same page here.

Can you please provide more details about your scenarios? We will work on a solution which will have little or no impact on Teamcity customers.

If you are using ##teamcity only for test reporting, why can't we use trx logger?

[martincostello]

With the console, TeamCity streams the test results to CI jobs in real time as they run. With .trx, don't you have to wait for the job to complete to get all the results at once from the XML file? Knowing a long-running test job is failing early on, rather than having to wait for the whole job to complete, is much more valuable.

[NikolayPianikov]

TeamCity service messages are useful for a set of scenarios like gathering statistics, code coverage, code inspections, attaching artifacts, build process's flow control. And as @martincostello mentioned it provides real-time feedback to the TeamCity server and users can save a lot of time.

TeamCity sends service messages when:

• user runs his build under TeamCity using .NET CLI Plugin (TeamCity specifies additional test adapter)
• user manually adds the reference to TeamCity.VSTest.TestAdapter into test project. In this case the TeamCity integration is working from any TeamCity runners (for example command line runner).

xunit (for dotnet core version only) sends TeamCity service messages when it finds the TEAMCITY_PROJECT_NAME environment variable for its proccess. It's like a way to determine if the xunit tests are runing under TeamCity server (to not publish TeamCity service messages from the users' command line). For the similar cases TeamCity is watching for output here and when it finds some serviece message it turn off its own propagation of service messages to avoid a duplication for test information.

There is an intresting moment: when verbosity level is quiet and users cannot see TeamCity service messages created by xunit and sended by console logger this code still RECEIVES notifications about actually filtered service messages.

Summarizing, TeamCity cannot process the case with xunit for dotnet core properly, meanwhile other cases are working as expected.

To minimize the consequences we have made verbosity levels as 'normal' by default for .NET CLI Plugin

For TeamCity.VSTest.TestAdapter we have made verbosity levels as 'normal' by default using the paramer VSTestVerbosity, excepted the case when user manually specifies other verbosity level.

But anyway it does not look very good

[smadala]

@NikolayPianikov Thanks for detail info. I will get back to you.

/cc @cltshivash @pvlakshm @mayankbansal018 @singhsarab FYI

[cltshivash]

@NikolayPianikov The verbosity levels of quiet and minimal shouldn't log information for successful tests. It was a bug that was fixed. Unfortunately the dependency has been taken on it and it is better to correct rather than let it remain for perpetuity.

[JamesFenton]

Hi, our team has just hit this problem. I agree with @joaopgrassi, this is a breaking change for users. dotnet test used to correctly report tests to TeamCity, and now it does not. I imagine dotnet test was supposed to make it easier to run tests, but the xunit and TeamCity integration has had multiple bugs.

[dtretyakov]

@JamesFenton, did you tried using logging verbosity parameter mentioned above? https://github.com/Microsoft/vstest/issues/1590#issuecomment-393460921

[JamesFenton]

@dtretyakov I did try it, and it does work. Its just annoying that dotnet test does not work out the box - I had to find a Github issue so that my build worked.