Capture StdOut from Console.WriteLine calls

[IloSophiep]

Context

At work we've recently switched a selenium project form .NET Framework to .NET core and are using dotnet test to execute the tests. Since we're using gitlab CI we needed a junit report, so we used this package's logger and in theory it works great.

The only problem, why we've "had to" switch to a combination of "trx logger + trx2junit" is, that we use Console.WriteLine(...) quite a lot to print information during the tests and sadly this logger does not seem to support those.

Request

It would be great to have the values send to Console.WriteLine(...)

• be shown in the stdout from the dotnet test --logger junit-call (that way the logging would show up in the job's log) OR / AND
• be added to the report XML, so we can just download the report-artifact if we need to look at the logging

As an aside: Thanks a lot for this project, and (i think) contributing to the gitlab documentation!

[Siphonophora]

@IloSophiep Yes, I added this to the gitlab docs, glad it was helpful.

I'm happy to dig into this in the next couple day. Were using the same integration with dotnet test as the trx logger, so I expect this would be straight forward.

My intuition here is that the proper role of this library is to put the standard out into system-out in the xml and not write it to the console, but let me think about that.

You may have seen, there are some command line flags specifically to reformat the report a little for GitLab. Best I can tell they only show the failure body in the UI, so the stdout would only be visible by downloading the artifact. Would it help to see the console output directly in the GitLab UI?

[IloSophiep]

Best I can tell they only show the failure body in the UI, so the stdout would only be visible by downloading the artifact. Would it help to see the console output directly in the GitLab UI?

Like i tried to say in the initial post, that would be good enough for us for sure! That's also what we currently do with the TRX logger. We take the TRX report and declare it as an artifact for download if we need to check the test logging. We also take the TRX report and convert it to a junit XML report, so we can use parts of the gitlab web UI for displaying failures.

If it is of any help, i could probably get you an example of the TRX report and the converted junit XML report on monday.

[Siphonophora]

@IloSophiep An example would be great.

[IloSophiep]

OK, i tried to prepare some example files.

I've added a example-files.zip, which contains:

• a peter.trx file, after running dotnet test --logger "trx;LogFileName=peter.trx" --filter ClassName=ExampleTests.BaseTests
• a peter.xml file, after running trx2junit .\peter.trx
• a cmd-calls.txt, which lists the two commands i mentioned above with their std out

I hope it's not a problem i "censored" some parts slightly.

[Siphonophora]

@IloSophiep Great, looks like thats everything I need. Will let you know when there is a pre-release package for you to try.

[Siphonophora]

@IloSophiep After looking at it some more, here is what I think makes sense to do.

1. The TRX format records the stdout per test, but Junit does not. Since it just stores one large blob of stdout for the whole run, we can split up that text by adding the test names.
2. I will modify the behavior of the FailureBodyFormat=Verbose flag so that it includes the stdout in the failure. This is mostly for gitlab, where it then allows you to see all the info you need for failures:
   

[Siphonophora]

@IloSophiep please give pre-release 2.1.34 a try.

I would suggest trying it like this to get output above in GitLab: dotnet test --test-adapter-path:. --logger:"junit;LogFilePath=..\artifacts\{assembly}-test-result.xml;MethodFormat=Class;FailureBodyFormat=Verbose"

[IloSophiep]

@IloSophiep please give pre-release 2.1.34 a try.

We tested the preview today! To be honest: We struggled a bit with installing the pre-release and couldn't get it to work on our CI server, because of Nuget proxies - but we were able to test the changes locally at least and check the result XML.

The result looks good and pretty much like what we had hoped for. I only later realized that the junit format does not seem to support saving the stdout as nicely as the TRX, but i think you found a decent way to work around that. We thought that maybe it would be even better to format the "blocks" in the <std-out> to be a bit more obvious? I think that's basically changing the lines 306 / 307 in src/JUnit.Xml.TestLogger/JUnitXmlTestLogger.cs to be a more obvious "section header" (leading line of "------" or something?). How do you feel about that?

Apart from that: Thanks for the fast work, much much appreciated!

[Siphonophora]

@IloSophiep Agreed, JUnit doesn't store the output as cleanly as trx.

Give 2.1.36 a try. I added some indentation to try and clean up the output. I think its easier to read the output now.

[IloSophiep]

Looks good to me, yeah. Three things:

• I was a bit surprised that the test case output is indented by three spaces - usually i would expect two or four
• When writing a test with a multiline logging for testing purposes i used \n to create a multiline output. That works in the "output window" in Visual Studio just fine, but does not create the indented result in your output. I checked your code and when i change it to {Environment.NewLine} it works. I just think it might be worth supporting the \n-case, because it will be very common i think?
• There are three spaces at the end of the std-out logging of every test case.

All of those are not really problems, just things i noticed

[codito]

@IloSophiep @Siphonophora is below a fair statement on the logging scope?

1. Stdout and Stderr captured for each test must be captured at the testcase/system-out and testcase/system-err` scope
2. Stdout and Stderr presented at the test run scope (excl. above) should be captured at the test-suite/system-out and test-suite/system-err scope

Now test run can include multiple assemblies, so the logging captured in (2) must be grouped on a per assembly basis?

(2) is more complex and test framework dependent. Is it a blocker for this issue? I'm thinking (2) should be solved at a different abstraction we're planning to build (spekt/testlogger).

[Siphonophora]

@codito I double checked and the schema I am using for Junit https://github.com/windyroad/JUnit-Schema/blob/master/JUnit.xsd includes only 1 level of system-out and system-err, at the test-suite level. So, I'm accumulating all the standard out to the test-suite level. That's why I included the command line flags to include test specific error messages in the failure body. I think the schema means we primarily do need to do option 2.

At the moment, I believe the library is only capable of running on one assembly at a time. My impression is that dotnet test was creating an instance of our logger for each assembly it ran tests on.

Totally un-related. Any reason not to add the spekt logo to the nuget package?

[codito]

Here's the junit xsd which led me to believe that there are 2 levels of system-out: https://github.com/junit-team/junit5/blob/master/platform-tests/src/test/resources/jenkins-junit.xsd

Any idea if this xsd is supported by gitlab? Which is the official one? Or we need to support both?

We can combine all outputs to the test-suite scope, not sure if that will help the user a lot since they need to find which test had the output. We can workaround that by prefixing the test name etc. probably. I think (1) would be the simplest unambiguous approach if it's supported by gitlab :)

Adding logo to the package is a good idea. Should we track it as a separate issue?

[codito]

From a quick search, it appears gitlab may be supporting test-case/system-out (see https://docs.gitlab.com/ee/ci/junit_test_reports.html#viewing-junit-screenshots-on-gitlab). I don't have a gitlab ci handy. Will wait for someone to confirm.

[Siphonophora]

Agreed. Logo is now #24

Picking which xsd to support was pretty difficult when this was getting started. I couldn't find anything that looked like a solid standard and left the disclaimer in the docs. We had an issue #16 before about producing xml that didn't validate against a particular xsd. We are now validating against the schema in our docs during the unit tests. Switching to the Jenkins schema would cause a failure, but it doesn't seem like its intentional.

Actual file doesn't specify minimum occurrences for property. The dotNet xml validation treats that like minOccurs="1" so we fail. All the other elements like this have a minimum specified.

<xs:element ref="property" maxOccurs="unbounded"/>

Probably should be this, in which case we pass:

<xs:element ref="property" minOccurs="0" maxOccurs="unbounded"/>

I do keep a mini pipeline setup on gitlab to test how the xml is displayed.

        <testcase name="MathTests.Multiply_ReturnsEight(1,0)" classname="ExampleTests.MathTests" time="0.016">
      <failure message="Assert.AreEqual failed. Expected:&lt;2&gt;. Actual:&lt;1&gt;. " type="not specified">   
  Assert.AreEqual failed.
     Expected: 8
     But Was: 0      

  Stack Trace:
     at ExampleTests.MathTests.TestMethod2() in P:\ath\MathTests.cs:line 38

  Standard Output:
Input a: 1
Input b: 0
Result 0
</failure>
<system-out>Here is some output.</system-out>
    </testcase>

Produces this UI:

Thats consistent with what I have seen. Gitlab only uses a few pieces of the schema, so in order to get the standard output to show, I am putting it inside the failure body.

If we use the new elements on the Jenkins schema the output will be clearer. But then any parser using the Ant schema would fail, which we know would happen to some users due to #16. What do you think about sticking with the current schema and opening tickets with Junit and Gitlab. Might also be worth it to reach out to circleCI / others to find out what they are doing. Then it will be easier to decide whether to support both schemas

[codito]

@Siphonophora thanks for the investigation!

What do you think about sticking with the current schema and opening tickets with Junit and Gitlab. Might also be worth it to reach out to circleCI / others to find out what they are doing. Then it will be easier to decide whether to support both schemas

Makes sense. Let's move ahead with (2). We will come back to (1) as needed in future.

From #22 (comment)

At the moment, I believe the library is only capable of running on one assembly at a time. My impression is that dotnet test was creating an instance of our logger for each assembly it ran tests on.

This is true for dotnet test. It forks new processes for each project. However, the underlying vstest platform can run multiple assemblies together. E.g. dotnet vstest a.dll b.dll or vstest.console.exe a.dll b.dll or from the IDE scenario when multiple test projects are present in a Solution. That said, the TestRunMessageHandler callback doesn't seem to provide a way to find which assembly is being run. We will have to put the stdout in all test-suites? Or do some complex calculation based on start/end time of an assembly run. We should probably keep it simple to start with.

We need to consider concurrency (for the case when tests may be running in parallel) in TestRunMessageHandler. Probably use a lock as rest of the code does?

[Siphonophora]

@codito After a little more digging, the Junit team has a long running issue related to creating a new xsd. junit-team/junit5#373 Also, the Jenkins schema was added to that project 4 years ago, so it isn't exactly new.

Agreed, if it can run in parallel it will need some locking, or maybe one of the concurrent collections to make that safe.

I will push resolutions to your comments and some formatting things @IloSophiep found later today.

[jdelucaa]

Hey guys,

I'm looking forward for this feature, I need the standard output to be printed out in the xml file just like the xunit testlogger does.
I couldn't find the pre-release version to test this one out, is that currently available?

[Siphonophora]

@jdelucca Here is the newest package from Pull #23. If you do try it, please let us know how it behaves.

https://www.myget.org/feed/spekt/package/nuget/JunitXml.TestLogger/2.1.40

[IloSophiep]

I got a bump about this issue, thanks to your comments.
Is there anything i am expected to (or can) help with?

To be honest: For now we're still just using the workaround with trx2junit in our CI - that said, i don't want to apply any pressure on how fast this point needs to be resolved. If a proper solution needs time, i won't complain.

[Siphonophora]

@IloSophiep I have been thinking a bit about the status of the PR. I'm pretty confident we are getting all the stdout and stderr into the xml report with these changes. I'm less confident we have the 'ideal' format for that text within the xml. Given that we know the xml is still compliant with the spec and the stdout is for human review, my thought is we could safely make any change to the format without needing to consider it a breaking change.

I don't use this sort of output in my own unit tests, so I haven't been able to do too much testing. If either you or @jdelucaa could give some feedback that would be great. If nothing jumps out as needing fixes, then I would tend to try and get this out in the field soon.

@jdelucaa Unrelated to the above. I am curious about your CI setup. If you sometimes need xunit and sometimes junit reports, I would be interested to learn why.

[jdelucaa]

Hey @Siphonophora ,

Thanks for the quick response. I tested it and it's exactly what I was looking for, one suggestion would be to write the output right after each test, like the xunit logger does, but it would be just an improvement, this already looks good. :)

About my CI setup:
All my services are based on junit xml format for the test results, I use them to publish the test results to Azure DevOps. I am currently using both loggers for the dotnet services because xunit provides the std out (which I need for some testing evidence), so I will probably drop it once this change in the junit logger gets released.

[Siphonophora]

@jdelucaa Thanks for the feedback. I think you may want this flag: FailureBodyFormat=Verbose. The junit format doesn't have a test level spot for stdout, but when a test fails we can add the stdout to the failure element. Unfortunately, for passing tests there isn't anywhere to put the stdout except at the end of the file.

[jdelucaa]

@Siphonophora Ok, thanks.
Do you have plans to release this anytime soon?

[Siphonophora]

@codito what do you think? I suspect it will be a while before we are ready to roll out the core package, so I don't think we should wait for that. I think this is in good shape and could be released with #27 (which needs a minor change) fairly soon.

[codito]

@Siphonophora 👍 let's roll this out fast to unblock everyone.

[Siphonophora]

@IloSophiep @jdelucaa This has been released in https://github.com/spekt/junit.testlogger/releases/tag/v2.1.78