Merge #896: Enable colour in console output

eb928bc fix: [#893] enable color for logs (Jose Celano)
a293373 chore(deps): add cargo dependency regex (Jose Celano)
a88082a fix: [#893] enable color in logs (Jose Celano)

Pull request description:

  Enable colour in console output.

  We were using the `logging` crate for logging. [We move to `tracing`](#884) but keeping the same format for logs. The only difference was the colour introduced by the `tracing` crate. This is just a patch to make allow using color with tracing. We parse the logs to extract the running services for example from these lines:

  ```
  2024-06-10T16:07:39.989540Z  INFO torrust_tracker::bootstrap::logging: logging initialized.
  2024-06-10T16:07:39.990205Z  INFO UDP TRACKER: Starting on: udp://0.0.0.0:6868
  2024-06-10T16:07:39.990215Z  INFO UDP TRACKER: Started on: udp://0.0.0.0:6868
  2024-06-10T16:07:39.990244Z  INFO UDP TRACKER: Starting on: udp://0.0.0.0:6969
  2024-06-10T16:07:39.990255Z  INFO UDP TRACKER: Started on: udp://0.0.0.0:6969
  2024-06-10T16:07:39.990261Z  INFO torrust_tracker::bootstrap::jobs: TLS not enabled
  2024-06-10T16:07:39.990303Z  INFO HTTP TRACKER: Starting on: http://0.0.0.0:7070
  2024-06-10T16:07:39.990439Z  INFO HTTP TRACKER: Started on: http://0.0.0.0:7070
  2024-06-10T16:07:39.990448Z  INFO torrust_tracker::bootstrap::jobs: TLS not enabled
  2024-06-10T16:07:39.990563Z  INFO API: Starting on http://127.0.0.1:1212
  2024-06-10T16:07:39.990565Z  INFO API: Started on http://127.0.0.1:1212
  2024-06-10T16:07:39.990577Z  INFO HEALTH CHECK API: Starting on: http://127.0.0.1:1313
  2024-06-10T16:07:39.990638Z  INFO HEALTH CHECK API: Started on: http://127.0.0.1:1313
  ```

  We extract these running services:

  ```json
  {
    "udp_trackers": [
      "127.0.0.1:6969"
    ],
    "http_trackers": [
      "http://127.0.0.1:7070"
    ],
    "health_checks": [
      "http://127.0.0.1:1313/health_check"
    ]
  }
  ```

  We should refactor the output format to take advantage of the new `tracing` crate. [`tracing` supports structured fields on spans and events](https://docs.rs/tracing/latest/tracing/#recording-fields), so it would be easier to parse those services.

ACKs for top commit:
  josecelano:
    ACK eb928bc

Tree-SHA512: 890b80df3688f8aedf6587a59cacc638df5f40c025ad0d361096362578844893b29a8d8963ccf28ab100d8296ea280fd0fcd876ef317c1363c6daaad4549954e

Cargo.toml

@@ -59,6 +59,7 @@ r2d2 = "0"
 r2d2_mysql = "24"
 r2d2_sqlite = { version = "0", features = ["bundled"] }
 rand = "0"
+regex = "1.10.5"
 reqwest = { version = "0", features = ["json"] }
 ringbuf = "0"
 serde = { version = "1", features = ["derive"] }

src/bootstrap/logging.rs

@@ -46,7 +46,7 @@ fn config_level_or_default(log_level: &Option<LogLevel>) -> LevelFilter {
 }
 
 fn tracing_stdout_init(filter: LevelFilter, style: &TraceStyle) {
-    let builder = tracing_subscriber::fmt().with_max_level(filter).with_ansi(false);
+    let builder = tracing_subscriber::fmt().with_max_level(filter).with_ansi(true);
 
     let () = match style {
         TraceStyle::Default => builder.init(),

src/console/ci/e2e/logs_parser.rs

@@ -1,9 +1,11 @@
 //! Utilities to parse Torrust Tracker logs.
+use regex::Regex;
 use serde::{Deserialize, Serialize};
 
-const UDP_TRACKER_PATTERN: &str = "UDP TRACKER: Started on: udp://";
-const HTTP_TRACKER_PATTERN: &str = "HTTP TRACKER: Started on: ";
-const HEALTH_CHECK_PATTERN: &str = "HEALTH CHECK API: Started on: ";
+const INFO_LOG_LEVEL: &str = "INFO";
+const UDP_TRACKER_LOG_TARGET: &str = "UDP TRACKER";
+const HTTP_TRACKER_LOG_TARGET: &str = "HTTP TRACKER";
+const HEALTH_CHECK_API_LOG_TARGET: &str = "HEALTH CHECK API";
 
 #[derive(Serialize, Deserialize, Debug, Default)]
 pub struct RunningServices {
@@ -52,19 +54,43 @@ impl RunningServices {
     ///
     /// NOTICE: Using colors in the console output could affect this method
     /// due to the hidden control chars.
+    ///
+    /// # Panics
+    ///
+    /// Will panic is the regular expression to parse the services can't be compiled.
     #[must_use]
     pub fn parse_from_logs(logs: &str) -> Self {
         let mut udp_trackers: Vec<String> = Vec::new();
         let mut http_trackers: Vec<String> = Vec::new();
         let mut health_checks: Vec<String> = Vec::new();
 
+        let udp_re = Regex::new(r"Started on: udp://([0-9.]+:[0-9]+)").unwrap();
+        let http_re = Regex::new(r"Started on: (https?://[0-9.]+:[0-9]+)").unwrap(); // DevSkim: ignore DS137138
+        let health_re = Regex::new(r"Started on: (https?://[0-9.]+:[0-9]+)").unwrap(); // DevSkim: ignore DS137138
+        let ansi_escape_re = Regex::new(r"\x1b\[[0-9;]*m").unwrap();
+
         for line in logs.lines() {
-            if let Some(address) = Self::extract_address_if_matches(line, UDP_TRACKER_PATTERN) {
-                udp_trackers.push(address);
-            } else if let Some(address) = Self::extract_address_if_matches(line, HTTP_TRACKER_PATTERN) {
-                http_trackers.push(address);
-            } else if let Some(address) = Self::extract_address_if_matches(line, HEALTH_CHECK_PATTERN) {
-                health_checks.push(format!("{address}/health_check"));
+            let clean_line = ansi_escape_re.replace_all(line, "");
+
+            if !line.contains(INFO_LOG_LEVEL) {
+                continue;
+            };
+
+            if line.contains(UDP_TRACKER_LOG_TARGET) {
+                if let Some(captures) = udp_re.captures(&clean_line) {
+                    let address = Self::replace_wildcard_ip_with_localhost(&captures[1]);
+                    udp_trackers.push(address);
+                }
+            } else if line.contains(HTTP_TRACKER_LOG_TARGET) {
+                if let Some(captures) = http_re.captures(&clean_line) {
+                    let address = Self::replace_wildcard_ip_with_localhost(&captures[1]);
+                    http_trackers.push(address);
+                }
+            } else if line.contains(HEALTH_CHECK_API_LOG_TARGET) {
+                if let Some(captures) = health_re.captures(&clean_line) {
+                    let address = format!("{}/health_check", Self::replace_wildcard_ip_with_localhost(&captures[1]));
+                    health_checks.push(address);
+                }
             }
         }
 
@@ -75,11 +101,6 @@ impl RunningServices {
         }
     }
 
-    fn extract_address_if_matches(line: &str, pattern: &str) -> Option<String> {
-        line.find(pattern)
-            .map(|start| Self::replace_wildcard_ip_with_localhost(line[start + pattern.len()..].trim()))
-    }
-
     fn replace_wildcard_ip_with_localhost(address: &str) -> String {
         address.replace("0.0.0.0", "127.0.0.1")
     }
@@ -127,6 +148,15 @@ mod tests {
         assert_eq!(running_services.health_checks, vec!["http://127.0.0.1:1313/health_check"]);
     }
 
+    #[test]
+    fn it_should_support_colored_output() {
+        let logs = "\x1b[2m2024-06-14T14:40:13.028824Z\x1b[0m  \x1b[33mINFO\x1b[0m \x1b[2mUDP TRACKER\x1b[0m: \x1b[37mStarted on: udp://0.0.0.0:6969\x1b[0m";
+
+        let running_services = RunningServices::parse_from_logs(logs);
+
+        assert_eq!(running_services.udp_trackers, vec!["127.0.0.1:6969"]);
+    }
+
     #[test]
     fn it_should_ignore_logs_with_no_matching_lines() {
         let logs = "[Other Service][INFO] Started on: 0.0.0.0:7070";

src/console/ci/e2e/runner.rs

@@ -116,7 +116,7 @@ pub fn run() -> anyhow::Result<()> {
 }
 
 fn tracing_stdout_init(filter: LevelFilter) {
-    tracing_subscriber::fmt().with_max_level(filter).with_ansi(false).init();
+    tracing_subscriber::fmt().with_max_level(filter).init();
     info!("Logging initialized.");
 }
 

src/console/clients/checker/app.rs

@@ -58,7 +58,7 @@ pub async fn run() -> Result<Vec<CheckResult>> {
 }
 
 fn tracing_stdout_init(filter: LevelFilter) {
-    tracing_subscriber::fmt().with_max_level(filter).with_ansi(false).init();
+    tracing_subscriber::fmt().with_max_level(filter).init();
     info!("logging initialized.");
 }
 

src/console/clients/udp/app.rs

@@ -127,7 +127,7 @@ pub async fn run() -> anyhow::Result<()> {
 }
 
 fn tracing_stdout_init(filter: LevelFilter) {
-    tracing_subscriber::fmt().with_max_level(filter).with_ansi(false).init();
+    tracing_subscriber::fmt().with_max_level(filter).init();
     info!("logging initialized.");
 }