Logging inside unit tests

Hi everyone,

I would like to write unit tests which log what they are doing. This per-test log output should only be shown in the case where the test fails, not when it passes.

I have looked at whether ounit2 and alcotest would provide this feature. OUnit2 has a logf function that is completely undocumented, and does not seem to do this. Alcotest has a verbose option that sends the stdout/stderr output of tests either to the terminal or to log files, but it does not mention having different output when the test fails.

Would you know of how to do this in an existing unit-test framework?

5 Likes

By default, Alcotest will capture the standard output / error streams for each test run in individual files. If there are failing tests, the logs of the first failing test case will be printed to standard output as part of the error reporting. This is modified by:

  • --verbose, which disables log capturing entirely, interleaving the test log stream with the result reporting. (I’m not sure why this was called “verbose”.)
  • --tail-errors=N, which prints only the last N lines of logs from the first failing test case.

I can’t vouch for what OUnit does here; perhaps someone with more experience with that library can chime in.

3 Likes

Thanks! This looks like the behavior I expect. Maybe it could be documented in the module documentation? I grepped for log and output in this documentation to tell if my use-case was handled; I learned that Alcotest captures/redirect stdout/stderr in the documentation of verbose, but not that the output of failing tests are displayed. (Now that I look at it again, the documentation of tail-errors does suggest this indirectly.)

2 Likes

Unfortunately, as of today, the most useful high-level introduction of the way Alcotest behaves is the “Examples” section in the README (and even that is very brief). From a maintainer’s perspective, this has the distinct advantage of supporting inline screenshots – and a picture paints a thousand words – but it’s unfortunate that docs.ocaml.pro doesn’t surface it. Contributions to improve the module documentation are very welcome :slight_smile:

At a higher level, I’d like to completely revamp the Alcotest documentation at some point – adding some mdx-hosted examples and a better introduction – but I suspect that’ll lead me towards writing a landing page that sits outside of the Odoc world (c.f. @jobjo’s excellent Popper documentation). My experience is that OCamldoc syntax works well for documenting OCaml APIs, but quickly becomes frustrating when documenting anything else (CLIs, encoding formats, protocols etc.).

2 Likes

I don’t mind having a document sitting outside the odoc realm (it could be linked from the top of the generated module documentation so that people don’t miss it). I went for docs.ocaml.pro because I didn’t find an other documentation page recommended on the README, so I assumed that this would be where to find reference documentation.

Contributions to improve the module documentation are very welcome

Here is a proposal: remplace

  • verbose (default false ). Display the test std.out and std.err (rather than redirecting to a log file).

by

  • verbose. Display the test std.out and std.err (rather than redirecting to a log file).
    By default, alcotest will include the std.out and std.err output of all tests in the log file,
    but it will only display it in the terminal for the first failing test.
1 Like

So we tried this feature with alcotest. It works well (thanks!), but in some more complex scenarios it doesn’t work well anymore; I think this could be improved but I’m not completely sure how.

Some of our tests are property-based tests and we were already using QCheck for those. QCheck offers some builtin alcotest integration in its QCheck_alcotest module, but the output capture does not work as the user would expect: QCheck will run say 1000 tests, one of them fails, I would like to see only the output of the failed test, but I get the output of all tests.

This is something that should be fixed in the QCheck_alcotest implementation, which is maintained by QCheck, not alcotest. But doing this would require access to the Log_trap machinery of alcotest (to capture the output of each sub-test independently), which is not exposed publicly, so it cannot be done without alcotest code changes.