Support a --nocapture mode in the test runner.

[lrowe]

When you have a mix of Rust println! and JS console.log output within a test the ------- output ------- marker may be written in the middle of the output. I found this confusing and it made me incorrectly fear that I was seeing the output reordered.

It may be worth adding a --nocapture mode similar to Rust's test runner which does not interfere with the output at all.

Example adding a console.log before the call to abort in this test and running with http tracing:

% cargo build -vv --features __http_tracing,__runtime_js_sources
% target/debug/deno test --trace-ops --unstable --allow-all cli/tests/unit/serve_test.ts --filter httpServerConcurrentRequests
Check file:///Users/lrowe/devel/deno/cli/tests/unit/serve_test.ts
running 1 test from ./cli/tests/unit/serve_test.ts
httpServerConcurrentRequests ...HTTP id=0x13a160b90 strong=1: HttpRecord::new
HTTP id=0x13a160b90 strong=2: handle_request response_ready.await
HTTP id=0x13a160b90 strong=2: op_http_set_response_header
HTTP id=0x13a160b90 strong=2: op_http_set_response_body_resource
HTTP id=0x13a160b90 strong=4: HttpRecord::complete
HTTP id=0x13a160b90 strong=3: handle_request complete
HTTP id=0x13972c370 strong=1: HttpRecord::new
HTTP id=0x13972c370 strong=2: handle_request response_ready.await
HTTP id=0x13972c370 strong=2: op_http_set_response_header
HTTP id=0x13972c370 strong=2: op_http_set_response_body_text
HTTP id=0x13972c370 strong=2: HttpRecord::complete
HTTP id=0x13972c370 strong=1: handle_request complete
HTTP id=0x13972c370 strong=1: HttpRecordResponse::drop
HTTP id=0x13972c370 strong=1: HttpRecord::finish success=true finalizers=1
HTTP id=0x13972c370 strong=1: HttpRecord::recycle inflight=6

------- output -------
abort
HTTP id=0x13a160b90 strong=3: HttpRecordResponse::drop
HTTP id=0x13a160b90 strong=3: HttpRecord::finish success=false finalizers=2
HTTP id=0x13a160b90 strong=1: op_http_finalizer_complete
HTTP id=0x13a160b90 strong=1: HttpRecord::recycle inflight=1
----- output end -----
httpServerConcurrentRequests ... ok (2s)

ok | 1 passed | 0 failed | 131 filtered out (3s)

Tracking this through the debugger it seems that there is no redirection of the process stdout/stderr within the thread. Instead when test creates a WebWorker it passes in a deno_io::Stdio which the worker then uses for its io. When console.log first writes to that Stdio::stdout/stderr it adds the marker. It doesn't see the process level stdout/stderr at all.

I'm not sure capturing the rust stdout is an options since it seems redirecting sdtout/stderr from within a process may potentially be problematic, see: https://stackoverflow.com/a/54432347. The gag crate linked there mentions an unstable function std::io:set_print which now seems to have been removed: rust-lang/rust#31343 (comment).

Incidentally, it seems the test runner only hides when log level is Some(level::Error), but the cli does not let you set this log level:

% deno test --log-level error
error: invalid value 'error' for '--log-level <log-level>'
  [possible values: trace, debug, info]

Possibly worth looking into alongside with #20707.

[lucacasonato]

I think this is an edge case, relevant for contributors only. We do not use println to display user output in the runtime (except for interactive things like permission prompts, but these are supressed during testing).

[lrowe]

It's not worth worrying about this for contributors to deno itself, but I believe the same issue could affect users of FFI extensions which print to stdout/stderr. For example the C postgres client library libpq will print notices to stderr unless it is hooked otherwise (which ideally a deno libpq wrapper would).

https://www.postgresql.org/docs/current/libpq-notice-processing.html

The default notice handling function prints the message on stderr, but the application can override this behavior by supplying its own handling function.

To be clear I don't think capturing the process level stdout/stderr is viable, but it could be worth providing a cli option which avoids writing out the additional markers mid way through a test.