Relates to:

• New feature: capture recent logs for testing (rework) #1149
• Unfinished attempt to use the tracing-test crate #1147
• New feature: capture recent logs for testing #1148
• New feature: capture recent logs for testing #1148

Some time ago I tried to use the tracing-test for writing assertions for logs. I could it use it because I had a bug described here:

#1148 (comment)

In the end, I decided to implement our own logging setup for testing, I copied part of the code from the tracing-test:

https://github.com/dbrgn/tracing-test/blob/main/tracing-test/src/subscriber.rs

That was included here:

https://github.com/torrust/torrust-tracker/blob/develop/packages/test-helpers/src/logging.rs

However I limited the buffer because I was planning to use it also in production.

I think I decided to copy because it gives us more control on the logging setup. If I remember well, the crate does its own initialization. And there's not much code.

One thing I could not make it work was using an span to identify logs for the tests we are writing the log assertions. It described on:

#1148 (comment)

We are using natural identifiers in the log lines to identify the logs related to the test we are running. For example the "request id".

@da2ce7 has opened an PR that might solve the problem. I guess we can test it adding a new test like this:

#[tokio::test]
async fn should_blab_bla() {
    logging::setup();

    let span = tracing::info_span!("unique scope");
    let _guard = span.enter();
    
    // test ...
    
    assert!(logs_contains_a_line_with(
        &["unique scope", "ERROR", "tower_http", "response failed"]
    ));    
}

It seems blocking functions could be the problem but I don't think so. As I mentioned in this comment I think the problem could be spans are not into the spawned threads when we run the test environments.

This is the PR opened by @da2ce7

I would keep our logging setup that gives us more flexibility but I would try to fix the problem using spans to identify logs for a tests.

cc @dbrgn