Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

stdout/stderr is not captured (only cout/cerr are) #2444

Open
davidmatson opened this issue Jun 3, 2022 · 8 comments · May be fixed by #2472
Open

stdout/stderr is not captured (only cout/cerr are) #2444

davidmatson opened this issue Jun 3, 2022 · 8 comments · May be fixed by #2472

Comments

@davidmatson
Copy link

Describe the bug
When a test case writes to stdout or stderr, it is never captured by the xml or junit reporters on Windows.

Expected behavior
When a test case writes to stdout or stderr, it is captured by the xml or junit reporters on Windows.

Reproduction steps

#include <string_view>
#include "catch2/catch.hpp"
#include <Windows.h>

TEST_CASE("Repro")
{
    // via stdlib
    printf("Some standard output\n");
    fprintf(stderr, "Some standard error\n");
    // via Win32 APIs
    constexpr std::string_view output{ "More standard output\n" };
    WriteFile(GetStdHandle(STD_OUTPUT_HANDLE), output.data(), (DWORD)output.size(), nullptr, nullptr);
    constexpr std::string_view error{ "More standard error\n" };
    WriteFile(GetStdHandle(STD_ERROR_HANDLE), error.data(), (DWORD)error.size(), nullptr, nullptr);
}

Platform information:
OS: Windows 10
Compiler: VS 2022 (17.2.2)
Catch version: 2.13.9

Additional context
The problem occurs regardless of whether -o is used or not; in both cases, stdout/stderr are never redirected. When not using -o, the resulting xml is not always valid (stdout/stderr interleaved in the XML).
Some examples:

Example 1
Command:
repro.exe -r xml
Output:

<?xml version="1.0" encoding="UTF-8"?>
<Catch name="repro.exe">
  <Group name="repro.exe">
    <TestCase name="Repro" filename="path\to\repro.cpp" line="5">
Some standard output
Some standard error
More standard output
More standard error
      <OverallResult success="true"/>
    </TestCase>
    <OverallResults successes="0" failures="0" expectedFailures="0"/>
    <OverallResultsCases successes="1" failures="0" expectedFailures="0"/>
  </Group>
  <OverallResults successes="0" failures="0" expectedFailures="0"/>
  <OverallResultsCases successes="1" failures="0" expectedFailures="0"/>
</Catch>

Example 2
Command:
repro.exe -r junit
Output:

<?xml version="1.0" encoding="UTF-8"?>
<testsuitesSome standard output
Some standard error
More standard output
More standard error
>
  <testsuite name="repro.exe" errors="0" failures="0" tests="0" hostname="tbd" time="0.001" timestamp="2022-06-03T00:05:04Z">
    <system-out/>
    <system-err/>
  </testsuite>
</testsuites>

Example 3
Command:
repro.exe -r xml -o result.xml
Output:

Some standard output
Some standard error
More standard output
More standard error

result.xml:

<?xml version="1.0" encoding="UTF-8"?>
<Catch name="Catch2Test.exe">
  <Group name="Catch2Test.exe">
    <TestCase name="Repro" filename="D:\Projects\Catch2Test\Catch2Test\tests.cpp" line="5">
      <OverallResult success="true"/>
    </TestCase>
    <OverallResults successes="0" failures="0" expectedFailures="0"/>
    <OverallResultsCases successes="1" failures="0" expectedFailures="0"/>
  </Group>
  <OverallResults successes="0" failures="0" expectedFailures="0"/>
  <OverallResultsCases successes="1" failures="0" expectedFailures="0"/>
</Catch>

Example 4
Command:
repro.exe -r junit -o result.xml
Output:

Some standard output
Some standard error
More standard output
More standard error

result.xml:

<?xml version="1.0" encoding="UTF-8"?>
<testsuites>
  <testsuite name="Catch2Test.exe" errors="0" failures="0" tests="0" hostname="tbd" time="0.001" timestamp="2022-06-03T00:09:14Z">
    <system-out/>
    <system-err/>
  </testsuite>
</testsuites>
@horenmar
Copy link
Member

horenmar commented Jun 3, 2022

Right, the issue isn't Windows, the issue is that the standard redirection only works for std::cout, std::clog and std::cerr. For various other ways to write to stdout/err, you have to use the experimental capture implementation.

@davidmatson
Copy link
Author

I see - thanks for the context.

For various other ways to write to stdout/err, you have to use the experimental capture implementation.

Any pointers on how to use that implementation?

We've had to do output redirection in the past on another project - let me know if there's a need for help with what technique to use here permanently (or if the existing experimental implementation already covers it and seems likely to ship).

Specifically, we've had good results with replacing the stdout/stderr handles at the C level, if I recall correctly.

@davidmatson davidmatson changed the title stdout/stderr is not captured on Windows stdout/stderr is not captured (only cout/cerr are) Jun 3, 2022
@horenmar
Copy link
Member

horenmar commented Jun 3, 2022

It is behind a compile-time toggle, specifically CATCH_CONFIG_EXPERIMENTAL_REDIRECT, and it works by duping the stdout/stderr handles, redirecting them while test is running and then restoring the original ones.

It has some compilation issues on less common platforms (e.g. missing posix parts), and IIRC runs into issues when too many tests are run in single binary (IIRC that's due to trying to open too many temp files). A help to make it more reliable would be appreciated, I think one of the first steps would be to make it so that each time redirection is engaged, it doesn't create a new temp file and instead rewinds & reuses the old one.

@davidmatson
Copy link
Author

Sounds good. On Windows, the standard approach is to use anonymous pipes, which avoids the need to maintain a temp file:
https://docs.microsoft.com/en-us/windows/win32/procthread/creating-a-child-process-with-redirected-input-and-output
(that's for a child process, but the same technique should work in-proc as well)

I'm not sure how Catch2 tends to handle OS-specific code though - would an optimized (no temp file) solution for Windows sound like a good idea (keeping the temp file approach on other OSes)?

@horenmar
Copy link
Member

horenmar commented Jun 4, 2022

It probably depends on how complex and maintainable the Windows impl would be. There are already different implementations for POSIXy platforms and Windows, but currently they are very similar to each other, which simplifies maintenance.

There is a good chance I would merge a specialized Windows impl.

@davidmatson
Copy link
Author

davidmatson commented Jun 8, 2022

Sounds good.

I did a little more digging, and anonymous pipes exist on POSIXy platforms as well:
https://linux.die.net/man/7/pipe

If we switched both Windows and POSIX over to use anonymous pipes, I suspect that would resolve the problems that showed up using temp files.

Do you think a pipes-based approach is a good idea overall (for both platforms), and do you think it could likely come out from behind the compile-time toggle and just be the way stdout/stderr redirection works (after some testing, of course)?

@ferdnyc
Copy link
Contributor

ferdnyc commented Jun 17, 2022

Do you think a pipes-based approach is a good idea overall (for both platforms),

(Chiming in) I think it's potentially a good idea. (Temporary files are always a nightmare, since somebody invariably ends up running into permissions problems in their installation.) But the danger with pipes is that they're not infinitely deep, and you have to keep them flushed or the writing end can end up blocking.

Python uses pipe-based redirection for processes launched by its subprocess module, and one of the biggest hassles (as basically everyone who's ever used it remembers, probably not fondly) is that you have to keep polling all of
the pipes for the entire process lifetime, even if you're not interested in some or even all of the output.

If you try to just read from the pipe you're interested in and ignore the others, or try to read from them sequentially in whatever arbitrary order you choose, it's incredibly easy to end up deadlocked:

  1. You're blocking on a read from an empty pipe
  2. The other pipe has been filled up
  3. That's caused the subprocess to block on writing to the full pipe
  4. Which will prevent it from ever writing more data to the one you're patiently staring into

(See the warning box in the Python docs that admonishes, "USE communicate() OR YOU'RE GONNA HAVE A BAD TIME!!" (paraphrased).)

So, when using pipes to capture output, the question always becomes: How are you going to ensure you stay on top of the pipes, regardless how much data is sent down them? If a test produces a lot of data, you're basically hosed unless you have a separate thread (if not a separate process) running in parallel just to ensure that the pipe keeps getting flushed while it's running. If your code only deals with the pipe contents in between tests, and some test is able to fill up a pipe, it'll never make it to the end and the flow of control won't be returned to your pipe-reader.

I'm not saying these are insurmountable problems, by any means. A careful implementation can certainly manage redirection using pipes without ending up deadlocked, or in any other condition that results in an exploded pipe spewing bits onto the basement floor. But it's worth noting: Pipes for output redirection can be a real pain in the... catch.

@davidmatson
Copy link
Author

But the danger with pipes is that they're not infinitely deep, and you have to keep them flushed or the writing end can end up blocking.

Yep, that's absolutely true.

If a test produces a lot of data, you're basically hosed unless you have a separate thread (if not a separate process) running in parallel just to ensure that the pipe keeps getting flushed while it's running.

Yes, having a thread dedicated to reading from the pipe (so the writer doesn't block) seems to be the most reliable technique (and also fairly simple).

davidmatson added a commit to davidmatson/Catch2 that referenced this issue Jun 30, 2022
Closes catchorg#2444.

Avoid the overhead of creating and deleting temporary files.
Anonymous pipes have a limited buffer and require an active reader to
ensure the writer does not become blocked. Use a separate thread to
ensure the buffer does not get stuck full.
davidmatson added a commit to davidmatson/Catch2 that referenced this issue Jul 3, 2022
Closes catchorg#2444.

Avoid the overhead of creating and deleting temporary files.
Anonymous pipes have a limited buffer and require an active reader to
ensure the writer does not become blocked. Use a separate thread to
ensure the buffer does not get stuck full.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants