dev: move from `log` to `tracing`

[da2ce7]

Transition to new modern library, with proper support for async instrumentation.

[codecov[bot]]

Codecov Report

Attention: Patch coverage is 62.34568% with 61 lines in your changes are missing coverage. Please review.

Project coverage is 78.25%. Comparing base (b5fb03b) to head (a086cff). Report is 16 commits behind head on develop.

Files	Patch %	Lines
src/bootstrap/tracing.rs	34.04%	31 Missing :warning:
src/console/ci/e2e/tracker_container.rs	0.00%	9 Missing :warning:
packages/configuration/src/lib.rs	83.87%	5 Missing :warning:
src/console/ci/e2e/runner.rs	0.00%	4 Missing :warning:
src/console/ci/e2e/trace_parser.rs	90.90%	4 Missing :warning:
src/console/clients/checker/app.rs	0.00%	3 Missing :warning:
src/console/clients/udp/app.rs	0.00%	3 Missing :warning:
src/console/ci/e2e/docker.rs	0.00%	2 Missing :warning:

Additional details and impacted files

@@             Coverage Diff             @@
##           develop     #782      +/-   ##
===========================================
+ Coverage    78.16%   78.25%   +0.09%     
===========================================
  Files          159      159              
  Lines         8863     8891      +28     
===========================================
+ Hits          6928     6958      +30     
+ Misses        1935     1933       -2     

:umbrella: View full report in Codecov by Sentry.
:loudspeaker: Have feedback on the report? Share it here.

[da2ce7]

@josecelano your cargo-pretty-test seems to be failing... hmm?

[josecelano]

@josecelano your cargo-pretty-test seems to be failing... hmm?

Hi, @da2ce7, I guess it's because the tests are now printing to the console even if, by default, they should not capture the output.

https://github.com/torrust/torrust-tracker/actions/runs/8610518996/job/23596178048?pr=782#step:7:84

The cargo-pretty-test cannot filter out custom output.

Anyway, I will check it. I'm not sure if we use only standard output. If that is an error output, we should discard those lines. I have to review your code to check how you are printing those lines.

[josecelano]

Hi @da2ce7, this is the patch (fie src/bootstrap/tracing.rs) for the cargo test output:

//! Setup for the application tracing.
//!
//! It redirects the tracing info to the standard output with the tracing level defined in the configuration.
//!
//! - `Off` (i.e. don't load any subscriber...)
//! - `Error`
//! - `Warn`
//! - `Info`
//! - `Debug`
//! - `Trace`
//!
//! Refer to the [configuration crate documentation](https://docs.rs/torrust-tracker-configuration) to know how to change tracing settings.
use std::sync::Once;

use torrust_tracker_configuration::{Configuration, TraceLevel};
use tracing::info;
use tracing::level_filters::LevelFilter;

static INIT: Once = Once::new();

/// It redirects the tracing info to the standard output with the tracing level defined in the configuration
pub fn setup(cfg: &Configuration) {
    let level = config_level_or_default(&cfg.tracing_max_verbosity_level);

    if level == LevelFilter::OFF {
        return;
    }

    INIT.call_once(|| {
        stdout_config(level);
    });
}

/// Option `tracing_max_verbosity_level` in configuration is mandatory but it can
/// be empty. The values are:
///
/// ```text
/// trace_level = ""       ->  Default is Info
/// trace_level = "Off"
/// trace_level = "Error"
/// trace_level = "Warn"
/// trace_level = "Info"
/// trace_level = "Debug"
/// trace_level = "Trace"
/// ```
fn config_level_or_default(trace_level: &TraceLevel) -> LevelFilter {
    if trace_level.to_string().is_empty() {
        return LevelFilter::OFF;
    }

    trace_level
        .to_string()
        .parse()
        .unwrap_or_else(|_| panic!("Tracing level filter is not valid: {trace_level}"))
}

fn stdout_config(filter: LevelFilter) {
    let () = tracing_subscriber::fmt().pretty().with_max_level(filter).init();

    info!("tracing initialized.");
}

The problem was the filter level running tests was not "Off" but the default one "Info".

By the way, good PR!

UPDATE

Maybe, we should consider not accepting an empty string for the filter level in the configuration. It would make sense to default to "Info" if the whole option is not present in the config file.

[josecelano]

@da2ce7 one question, can we disable the location in the output for production:

  2024-04-09T05:22:25.044249Z  INFO torrust_tracker::console::ci::e2e::tracker_container: Running docker tracker image: tracker_HdsddtwXcLcZFrphp1Re ...
    at src/console/ci/e2e/tracker_container.rs:51

I would add the line at src/console/ci/e2e/tracker_container.rs:51 only for "Debug" and "Trace" levels.

UPDATE

That's also making some E2E tests fail.

  2024-04-09T05:22:25.044249Z  INFO torrust_tracker::console::ci::e2e::tracker_container: Running docker tracker image: tracker_HdsddtwXcLcZFrphp1Re ...
    at src/console/ci/e2e/tracker_container.rs:51

  2024-04-09T05:22:25.399178Z  INFO torrust_tracker::console::ci::e2e::tracker_container: Waiting for the container tracker_HdsddtwXcLcZFrphp1Re to be healthy ...
    at src/console/ci/e2e/tracker_container.rs:55

  2024-04-09T05:22:31.498433Z  INFO torrust_tracker::console::ci::e2e::tracker_container: Container tracker_HdsddtwXcLcZFrphp1Re is healthy ...
    at src/console/ci/e2e/tracker_container.rs:61

thread 'main' panicked at src/console/ci/e2e/tracker_container.rs:130:49:
Traces should be captured from running container: Custom { kind: Other, error: "Failed to fetch traces from Docker container tracker_HdsddtwXcLcZFrphp1Re" }
  2024-04-09T05:22:31.510711Z  INFO torrust_tracker::console::ci::e2e::tracker_container: Dropping tracker container: tracker_HdsddtwXcLcZFrphp1Re
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
    at src/console/ci/e2e/tracker_container.rs:22

tracker_HdsddtwXcLcZFrphp1Re
  2024-04-09T05:22:31.930247Z  INFO torrust_tracker::console::ci::e2e::docker: Dropping running container: tracker_HdsddtwXcLcZFrphp1Re
    at src/console/ci/e2e/docker.rs:23

However, I have yet to check if the problem is parsing the output.

[josecelano]

Relates to: https://github.com/torrust/torrust-tracker/issues/727

[josecelano]

Displaced by https://github.com/torrust/torrust-tracker/pull/888. However, one of the features introduced in the PR has not been added to that PR. Rather I've opened a new issue.