Output errors to stderr

[pianistrevor]

Use stderr more appropriately

When unit tests run, certain information is output to stdout, and other information to stderr. It would be nice if the only information output to stderr were actual errors.

[ianfixes]

Hi Trevor, thanks for this suggestion! Can you post a link or snippet of code that you are referring to?

What you see when you run arduino_ci is the output of a Ruby program. The Ruby code explores the working directory for various indicators of Arduino library structure and .arduino_ci.yaml config files, then runs unit tests and compilation tests as configured. For unit tests, this means that the Ruby code invokes the C++ compiler to generate a binary that will perform the unit tests. Then, it executes the binary and captures/parses the output.

To prevent losing output due to segfaults in a unit test binary, all the output is sent to STDERR. I'm not sure if that's what you're referring to in this case, but if so then that's why I'm using STDERR (and it's unlikely that I'll be able to un-architecture that decision).

Do you have a build log somewhere that we could both look at?

[jgfoster]

I've been working with Trevor and we should have a PR shortly that demonstrates the proposed change...

Does output to stdout get lost due when there is a segfault?

[ianfixes]

Output to STDOUT may be lost if the segfault happens after text has been sent to STDOUT but before the STDOUT stream is flushed. Since STDERR is flushed on every write, you are guaranteed to see debug messages (in this case, the TAP-formatted test messages from the binary)

[pianistrevor]

#322 should fix these issues.

[ianfixes]

I'd like to understand the use case of "information being printed to STDERR" a bit more. What is the use case here? Or what is an example of problematic output?

[pianistrevor]

If we split STDOUT and STDERR for efficiency of knowing which tests fail (for example, in a particularly large test suite), it’s much more convenient to send only the test errors to STDERR and the rest to STDOUT. A problem might be, “I ran 247 tests and had 1 failure, now you have to scroll through all 247 to find the one X mark.”

[pianistrevor]

Via std::cerr on cppreference:

"In addition, std::cerr.tie() returns &std::cout (same for wcerr and std::wcout), meaning that any output operation on std::cerr first executes std::cout.flush() (via std::basic_ostream::sentry's constructor)"

[ianfixes]

A problem might be, “I ran 247 tests and had 1 failure, now you have to scroll through all 247 to find the one X mark.”

This is a fairly compelling use case. It would be trivial to update the ruby script to add a summary of test failures at the end of the output, if that's the motivation for this change.

[hlovdal]

It would be trivial to update the ruby script to add a summary of test failures at the end of the output.

That sounds like an excellent idea in any case.

[ianfixes]

After starting on this, I remembered that it was my plan to do this via a TAP ("Test Anything Protocol") parser. That would give me full programmatic flexibility to capture the output from the test harnesses and present it more sensibly to the user.

At the time, there wasn't a library available for this and I didn't have time to write my own from scratch. That situation seems to have changed though: https://github.com/vincent-psarga/ruby-tap-parser

I will give this a bit more thought.

[ianfixes]

I made progress toward this goal
https://github.com/ianfixes/tap_parser

The current plan is to roll the individual unit tests' TAP output into a larger test + subtest report (built into the current functions of the test runner that provide the pass/fail and indentation text) then summarize the failures from the whole test run at the very end.