prevent confusing debugging experience when users write garbage to stdout, interfering with the build runner / test runner protocol

[gitusel]

Zig Version

0.11.0-dev.2297+28d6dd75a

Steps to Reproduce and Observed Behavior

1/ zig init-lib
2/ Correct test_step.dependOn(&main_tests.step); to test_step.dependOn(&main_tests.run().step);
3/ src/main.zig
const std = @import("std");
test "t" {
const writer = std.io.getStdOut().writer();
var buffered_writer = std.io.bufferedWriter(writer);
var stdout_writer = buffered_writer.writer();
stdout_writer.print("TEST: t\n", .{}) catch @Panic("PANIC!\n");
buffered_writer.flush() catch @Panic("PANIC!\n");
}

4/ run zig build test. The test stalled and you need to exit using ctrl+c.

Expected Behavior

The test should run and exit.

If using stdErr, e.g. changing const writer = std.io.getStdOut().writer(); to const writer = std.io.getStdErr().writer(); will make it passed.

[jacobly0]

After the build parallel changes, stdout is now used to communicate progress to the build exe so that it can display aggregate progress for all simultaneously running test processes. Do you have a specific use case for writing to stdout instead of stderr from a test?

[gitusel]

If for any reason a function is displaying something then it will be blocked, e.g.:
const std = @import("std");
fn t() u8 {
const writer = std.io.getStdOut().writer();
var buffered_writer = std.io.bufferedWriter(writer);
var stdout_writer = buffered_writer.writer();
stdout_writer.print("TEST: t\n", .{}) catch @Panic("PANIC!\n");
buffered_writer.flush() catch @Panic("PANIC!\n");
return 0;
}

test "t" {
try std.testing.expect(t() == 0);
}

will also never exit.

[jacobly0]

By use case, I mean a specific motivating example, not "any reason". This involves more of an explanation for why the function is required to write to standard out and why it benefits from being tested than necessarily specific code. Based on the example, it vaguely suggests that the function just wants to print some testing status to stdout, which if even this were allowed, wouldn't work very well now that multiple test processes can be running at the same time. The current behavior is to collect all stderr and print it after the test runs, which is useful for descriptions of test failures, but not very useful for live status updates.

I do have an idea for addressing the hanging issue. At least on linux, stdout could be dup'd and closed when used by the test runner so that other code can't accidentally write to it. The descriptor could even be replaced with a handle to /dev/null so that bad code that does use it at least won't error (and to avoid it getting replaced with another open'd descriptior I guess), but I'm not sure which behavior is more desirable.

[gitusel]

Not sure to understand what you are looking for. But for instance, simple logging to stdOut. The code shared is a simplified version to show the issue. The solution to leverage stdOut as an internal channel between a test and build exe does not appear viable.

[jacobly0]

A reduced example is very valuable for demonstrating the issue, and in this case I agree that the example doesn't work as expected and so that has served its purpose. However, by reducing the example, there tends to be a lot of lost context that can be filled in by an explanation of what you were trying to accomplish when you ran into the issue. If the answer is that you don't specifically need stdout to work, but you just wanted to log something and happened to use stdout, expecting it to work, then that is a perfectly valid use case, and you are just missing a description of what you wanted to log (test progress, test result status, failure description, debug prints, actually testing a "log something to stdout" function, etc) and why logging to stderr instead does not solve this use case. Note that std.log uses stderr by default, so there's nothing inherent about the term "logging" that implies a requirement to use stdout in this context.

[gitusel]

(Un)fortunately, in this particular case, the library I translated is using its own logging framework and it relies on stdout. I think that the IPC between the build exe and the test RunStep has to be private.

[gitusel]

It is not confusion but test run never exits.

[karlseguin]

I just ran into this too.

Do you have a specific use case for writing to stdout instead of stderr from a test

It doesn't have to be the test that writes to stdout for it to hang, it can be the code under test. For example, this hangs

fn echo(data: []const u8) !void {
	try std.io.getStdOut().writeAll(data);
}

test "echo" {
	try echo("hello");
}

This is obviously a minimal example to reproduce the issue. But I don't think it's an edge-case that code under test, maybe through a library and maybe directly, might want to use stdout.

[karlseguin]

@andrewrk I guess I can see how being able to use stdout is considered an enhancement. But "zig build test" hanging when a function in the standard library is used should surely be classified as a bug?

[nektro]

std.testing.expectEqualStrings() is currently unusable as of this

edit: the test part works, specifically the debugging output that makes it more useful than expect(std.mem.eql(a, b))

[gitusel]

Hi @andrewrk. Any progress on runner and builder communication design? It is very problematic to me that this issue is not recognized as a fundamental flaw in the current test framework. It is also the very first time that a test framework is imposing to me the way my program should communicate with its user.

[HeCorr]

I started learning the language today and was really confused by my very simple test hanging when trying to print to stdout.

Printing with std.debug.print() (or directly to stderr) adds an error: prefix, which can also be pretty confusing (because I'm trying to log a value, not an error) so it's definitely not desirable for my use-case.

[HeCorr]

@gitusel this seems to be an issue with running the tests with zig build test.

A Reddit user suggested trying zig test instead and it did work for me. Could you try that?

[gitusel]

@HeCorr, zig test and zig build test are not exactly the same. https://zig.news/slimsag/my-hopes-and-dreams-for-zig-test-2pkh

[Lking03x]

I have the same problem #16916, As I was using the tests to test language features and my code implementation (rather than testing an already written code). Since it's not a use case, as I figured out, it's should be an error to print to stdout during test.
Or there should be a warning about Undefined Behavior in the documentation or even the compile.

As for external libraries using stdout, it's a dipper problem.

[andrewrk]

There's an easy way to understand who owns standard in and standard out. Whichever component has the main() function. In the case of zig unit testing, the unit test themselves are not part of an application that has a main() function. It is the test runner that has the main function, and it is the test runner that gets to decide what to do with stdin and stdout.

stderr, on the other hand, is available to write things to, although I would recommend std.log instead so that the test runner can handle those messages appropriately.

Don't write to stdout if you are not the main application!

[rootbeer]

So no code that is invoked indirectly by a test case can write to stdout either? That seems very limiting. Especially when the failure mode is a silent hang.

It is also surprising and confusing for tests that work under zig test to hang under zig build test.

EDIT: std.debug.print goes to stderr, ignore this:

This design also precludes adding a std.debug.print to debug test failures.

AFAICT, the test runner itself can write to stdout in rare cases:

            else => {
                std.debug.print("unsupported message: {x}", .{@intFromEnum(hdr.tag)});
                std.process.exit(1);
            },

If you want to keep stdout for the test runner's protocol, would you accept changes that make the stdout writer panic (to stderr!) if they're used during a test?

[Beyley]

So no code that is invoked indirectly by a test case can write to stdout either? That seems very limiting. Especially when the failure mode is a silent hang.

It is also surprising and confusing for tests that work under zig test to hang under zig build test.

This design also precludes adding a std.debug.print to debug test failures.

AFAICT, the test runner itself can write to stdout in rare cases:

            else => {
                std.debug.print("unsupported message: {x}", .{@intFromEnum(hdr.tag)});
                std.process.exit(1);
            },

If you want to keep stdout for the test runner's protocol, would you accept changes that make std.debug.print() and the stdout writer panic (to stderr!) if they're used during a test?

std.debug.print already uses stderr

zig/lib/std/debug.zig

Line 82 in 46062f1

/// Print to stderr, unbuffered, and silently returning on failure. Intended

[rootbeer]

Ack, sorry to confuse things. You're right.

[slonik-az]

There's an easy way to understand who owns standard in and standard out.

More fundamentally, why stdout was chosen as communication channel for the test runner protocol in the first place? Why not some other non-standard file descriptor like fd=3? In this case stdout will be available to the user alongside stderr. Am I missing something?

[nektro]

afaik changing the behavior is planned, but its because unit tests are not supposed to have side effects and using std.log does still work

[slonik-az]

afaik changing the behavior is planned, but its because unit tests are not supposed to have side effects and using std.log does still work

Changing file descriptor from fd=1 (stdout) to unassigned one (like fd=3) will not introduce any side effects and existing tests should run exactly the same way as before.

[gitusel]

Once again, it has nothing to do with "unit tests which are not supposed to have side effects" or "who has the main() function decides". It has to do with 1/ it worked before the introduction of parallel test runners, 2/ the framework assumes that all std file descriptors are available, which to me is a major design flaw, 3/ it doesn't fail but hang resulting in blocking CI pipelines, 4/ The documentation never states that the framework is only intended for unit testing and in addition for functions without side effects on at least stdout (and may be more - who knows?).

[aalbacetef]

Ran into this issue and unfortunately not only does it lead one to chase dead ends trying to debug it (zig build test just hangs), it's not necessarily clear in the docs (particularly the testing section) that it will hang when writing to stdout.

It should probably be documented with some kind of warning in the docs.

For anyone wanting a quick solution, the following one liner will get you some of the way (drop it in a Makefile/Justfile/taskrunner of choice):

find src -name '*.zig' -exec zig test {} \;

Or, refactor your code to use a generic writer (e.g: writer: anytype) and pass in something else in tests. One advantage is that in unit tests you can pass in a writer of your choice (e.g: from std.io.FixedBufferStream) to ensure your writing functions are doing what they're supposed to do.

[mnemnion]

The bug is here. As you can see, evalZigTest tries to read stdout directly into the Header struct. This is incorrect, because the Zig build system does not control the contents of stdout.

As you read down, you'll see that, when it receives spurious data, no further tests are requested. So we have a deadlock: the test process waits for the requestNextTest, which it never receives, and so we get an endless polling loop until the user sends a ^C.

There is a relatively simple fix available: instead of presuming that the header will be sent immediately, which will not, in full generality, happen, the polling can look for a magic string, such as a UUID. The test runner will send this string, followed by the header and payload.

Since the nature of a UUID is such that it cannot be sent accidentally, this will work unless the user decides to spoof the build system (which is already possible). This is not a case which needs to be accounted for.

Anything before each magic string is user data: this can put put onto another FIFO, or, if the doctrine that impure effectful use of stdout must not be rewarded is upheld, silently discarded. Given that various stderr printings are permitted, it seems reasonable to me to do the former, and batch up "garbage to stdout", to print once the test completes.

Either way, this fixes the build system bug, where it hangs due to invalid parsing. A testing system should hang under one circumstance only: when the code it is testing hangs.

My suggestion is that, rather than treating this as an enhancement, it get the bug and Contributor Friendly label.