feature request: log 4xx requests as info during tests

[skyqrose]

Current:

• I have Logster 2.0.0-rc.3 installed with all default settings. Phoenix logging is disabled.
• My tests have minimum log level set to warning.
• I run a test that intentionally triggers a 400 error.
• The output includes the Logster output, at level warning, due to the default implementation of log_level.

This log message is not useful to me. Any 4xx warnings during testing are ones that I either intentionally triggered, or would cause a test to fail. And they clutter the output to obscure things that I do want to see, like test failures.

So I want to prevent Logster from logging from 4xx responses during testing.

Here's an example output from mix test:

................15:47:22.686 request_id=F-4kr01EGf1rw7kAAAck [warning] state=sent method=POST path=<REDACTED> params={<REDACTED>} status=401 duration=21.909
......15:47:22.808 request_id=F-4kr1UVJeUJv6MAAAgE [warning] state=sent method=POST path=<REDACTED> controller=<REDACTED> action=<REDACTED> params={<REDACTED>} status=404 duration=13.680
..15:47:22.816 request_id=F-4kr1ZZ4WdyocYAAAJj [warning] state=sent method=GET path=<REDACTED> params={<REDACTED>} status=401 duration=0.055
.........15:47:22.840 request_id=F-4kr1e2bw-1Qd8AAAGC [warning] state=sent method=POST path=<REDACTED> controller=<REDACTED> action=<REDACTED> params={<REDACTED>} status=400 duration=1.646
.15:47:22.843 request_id=F-4kr1fyDEpDpzwAAAgk [warning] state=sent method=POST path=<REDACTED> controller=<REDACTED> action=<REDACTED> params={} status=405 duration=0.212
.15:47:22.845 request_id=F-4kr1gVnezM5HcAAADo [warning] state=sent method=POST path=<REDACTED> controller=<REDACTED> action=<REDACTED> params={} status=403 duration=0.218
..15:47:22.852 request_id=F-4kr1iEN7l04wAAAALj [warning] state=sent method=POST path=<REDACTED> controller=<REDACTED> action=<REDACTED> params={} status=400 duration=0.298
...15:47:22.863 request_id=F-4kr1kpmUo0w4IAAAik [warning] state=sent method=GET path=<REDACTED> controller=<REDACTED> action=<REDACTED> params={} status=403 duration=0.211
.........15:47:22.891 request_id=F-4kr1rRU7z0su4AAAGi [warning] state=sent method=GET path=<REDACTED> controller=<REDACTED> action=<REDACTED> params={<REDACTED>} status=400 duration=0.046
.......................................
Finished in 0.4 seconds (0.1s async, 0.3s sync)
88 tests, 0 failures

Randomized with seed 513392

And here's what I would want to see when all tests pass:

........................................................................................
Finished in 0.4 seconds (0.1s async, 0.3s sync)
88 tests, 0 failures

Randomized with seed 513392

Potential workarounds:

• Configure minimum log level to error when testing. But this would obscure other warning logs from other parts of my app, which could be useful to see.
• Configure Logster to always log as info, or entirely mute Logster in testing. But I do want to see error logs from 500 responses, which I don't expect to intentionally see in testing, so would not cause noise. (This workaround is what I'm doing for now.)
• Set the Plug.Telemetry :log option (as described in the documentation). But this would require a bit of code, and it would be a little bit messy to configure my app to use a custom version in testing and the default version in other mix environments.

My ideal solution would be something that tells Logster to log 4xx requests as info, so they get hidden behind the minimum log level (but I could see them if I turned my testing log level down), and something I could do by only setting some config in config/test.exs so it doesn't affect how Logster works in prod.

[navinpeiris]

Hi @skyqrose, thanks for the feature idea, will have a look at enabling custom log levels per status code group per environment soon, and will keep this issue opened until that's resolved.

In the meantime, can I suggest running your tests with:

ExUnit.start(capture_log: true)

What this will do is suppress logs regardless of error level for passing tests, and print all the relevant log messages for failing tests. This works for any logging you do through Logster, Logger or any other logging framework. See this elixir school post for more info.

[skyqrose]

Thank you! That's a better solution than I was hoping for! Grouping the relevant logs next to the failing test is really nice. This should just be the default for ExUnit. It does mean unexpected warnings and errors during a passing test would be quieted, but I think that's a fine tradeoff to avoid having to specify which logs to quiet.