remove main logger

The main logger was not useful and created conflicts.
* Homogenize setup_logging accross the whole codebase
* take RUST_LOG into account everywhere

* fix tag error introduced by 3a4e4fd
    the line read_requests_from_file called a function
    and a log statement from the workspace sozu_command_lib
    before a Logger was properly initialized, which caused
    the default logger to be used by the worker (error, "SOZU")

Co-Authored-By: Eloi DEMOLIS <eloi.demolis@clever-cloud.com>

bin/Cargo.toml

@@ -31,7 +31,6 @@ futures = "^0.3.28"
 futures-lite = "^1.13.0"
 hex = "^0.4.3"
 jemallocator = { version = "^0.5.4", optional = true }
-lazy_static = "^1.4.0"
 libc = "^0.2.149"
 log = "^0.4.20"
 mio = { version = "^0.8.8", features = ["os-poll", "net"] }

bin/src/ctl/mod.rs

@@ -4,12 +4,13 @@ use anyhow::Context;
 use sozu_command_lib::{
     channel::Channel,
     config::Config,
+    logging::setup_logging_with_config,
     proto::command::{Request, Response},
 };
 
 use crate::{
     cli::{self, *},
-    get_config_file_path, load_configuration, util,
+    get_config_file_path, load_configuration,
 };
 
 mod command;
@@ -27,7 +28,7 @@ pub fn ctl(args: cli::Args) -> anyhow::Result<()> {
     let config_file_path = get_config_file_path(&args)?;
     let config = load_configuration(config_file_path)?;
 
-    util::setup_logging(&config, "CTL");
+    setup_logging_with_config(&config, "CTL");
 
     // If the command is `config check` then exit because if we are here, the configuration is valid
     if let SubCmd::Config {

bin/src/main.rs

@@ -23,8 +23,6 @@
 //! which means other programs can use the protobuf definition and send roquests
 //! to Sōzu via its UNIX socket.
 
-#[macro_use]
-extern crate lazy_static;
 #[macro_use]
 extern crate prettytable;
 #[macro_use]
@@ -38,9 +36,6 @@ extern crate num_cpus;
 #[global_allocator]
 static ALLOC: jemallocator::Jemalloc = jemallocator::Jemalloc;
 
-#[macro_use]
-mod logging;
-
 /// the arguments to the sozu command line
 mod cli;
 /// Receives orders from the CLI, transmits to workers
@@ -63,7 +58,7 @@ use libc::{cpu_set_t, pid_t};
 #[cfg(target_os = "linux")]
 use regex::Regex;
 use sozu::metrics::METRICS;
-use sozu_command_lib::config::Config;
+use sozu_command_lib::{config::Config, logging::setup_logging_with_config};
 use std::panic;
 
 use crate::worker::{get_executable_path, start_workers, Worker};
@@ -122,7 +117,7 @@ fn start(args: &cli::Args) -> Result<(), anyhow::Error> {
     let config_file_path = get_config_file_path(args)?;
     let config = load_configuration(config_file_path)?;
 
-    util::setup_logging(&config, "MAIN");
+    setup_logging_with_config(&config, "MAIN");
     info!("Starting up");
     util::setup_metrics(&config).with_context(|| "Could not setup metrics")?;
     util::write_pid_file(&config).with_context(|| "PID file is not writeable")?;

bin/src/upgrade.rs

@@ -16,8 +16,8 @@ use serde::{Deserialize, Serialize};
 use tempfile::tempfile;
 
 use sozu_command_lib::{
-    channel::Channel, config::Config, proto::command::RunState, request::WorkerRequest,
-    state::ConfigState,
+    channel::Channel, config::Config, logging::setup_logging_with_config, proto::command::RunState,
+    request::WorkerRequest, state::ConfigState,
 };
 
 use crate::{command::CommandServer, util, worker::Worker};
@@ -155,7 +155,7 @@ pub fn begin_new_main_process(
         serde_json::from_reader(upgrade_file).with_context(|| "could not parse upgrade data")?;
     let config = upgrade_data.config.clone();
 
-    util::setup_logging(&config, "MAIN");
+    setup_logging_with_config(&config, "MAIN");
     util::setup_metrics(&config).with_context(|| "Could not setup metrics")?;
     //info!("new main got upgrade data: {:?}", upgrade_data);
 

bin/src/util.rs

@@ -7,8 +7,6 @@ use nix::fcntl::{fcntl, FcntlArg, FdFlag};
 use sozu::metrics;
 use sozu_command_lib::config::Config;
 
-use crate::logging;
-
 pub fn enable_close_on_exec(fd: RawFd) -> Result<i32, anyhow::Error> {
     let file_descriptor =
         fcntl(fd, FcntlArg::F_GETFD).with_context(|| "could not get file descriptor flags")?;
@@ -36,16 +34,6 @@ pub fn disable_close_on_exec(fd: RawFd) -> Result<i32, anyhow::Error> {
     fcntl(fd, FcntlArg::F_SETFD(new_flags)).with_context(|| "could not set file descriptor flags")
 }
 
-pub fn setup_logging(config: &Config, tag: &str) {
-    //FIXME: should have an id for the main too
-    logging::setup(
-        tag.to_owned(),
-        &config.log_level,
-        &config.log_target,
-        config.log_access_target.as_deref(),
-    );
-}
-
 pub fn setup_metrics(config: &Config) -> anyhow::Result<()> {
     if let Some(metrics) = config.metrics.as_ref() {
         return Ok(metrics::setup(

bin/src/worker.rs

@@ -29,7 +29,7 @@ use sozu::{metrics, server::Server};
 use sozu_command_lib::{
     channel::Channel,
     config::Config,
-    logging::target_to_backend,
+    logging::setup_logging_with_config,
     proto::command::{request::RequestType, Request, RunState, Status, WorkerInfo},
     ready::Ready,
     request::{read_requests_from_file, WorkerRequest},
@@ -38,7 +38,7 @@ use sozu_command_lib::{
     state::ConfigState,
 };
 
-use crate::{logging, util};
+use crate::util;
 
 /// An instance of Sōzu, as seen from the main process
 pub struct Worker {
@@ -225,39 +225,23 @@ pub fn begin_worker_process(
 
     let mut configuration_state_file = unsafe { File::from_raw_fd(configuration_state_fd) };
 
-    let initial_state = read_requests_from_file(&mut configuration_state_file)
-        .with_context(|| "could not parse configuration state data")?;
-
     let worker_config = worker_to_main_channel
         .read_message()
         .with_context(|| "worker could not read configuration from socket")?;
 
     let worker_id = format!("{}-{:02}", "WRK", id);
-    logging::setup(
-        worker_id.clone(),
-        &worker_config.log_level,
-        &worker_config.log_target,
-        worker_config.log_access_target.as_deref(),
-    );
+
+    // do not try to log anything before this, or the logger will panic
+    setup_logging_with_config(&worker_config, &worker_id);
 
     trace!(
         "Creating worker {} with config: {:#?}",
         worker_id,
         worker_config
     );
-
-    let backend = target_to_backend(&worker_config.log_target);
-    let access_backend = worker_config
-        .log_access_target
-        .as_deref()
-        .map(target_to_backend);
-    sozu_command_lib::logging::Logger::init(
-        worker_id.clone(),
-        &worker_config.log_level,
-        backend,
-        access_backend,
-    );
     info!("worker {} starting...", id);
+    let initial_state = read_requests_from_file(&mut configuration_state_file)
+        .with_context(|| "could not parse configuration state data")?;
 
     if let Err(e) = worker_to_main_channel.nonblocking() {
         error!("Could not unblock the worker-to-main channel: {}", e);

command/src/logging.rs

@@ -14,9 +14,11 @@ use libc;
 use mio::net::UnixDatagram;
 use rand::{distributions::Alphanumeric, thread_rng, Rng};
 
+use crate::config::Config;
+
 thread_local! {
   pub static LOGGER: RefCell<Logger> = RefCell::new(Logger::new());
-  pub static TAG:    String          = LOGGER.with(|logger| logger.borrow().tag.clone());
+  pub static TAG: String = LOGGER.with(|logger| {logger.borrow().tag.clone()});
 }
 
 pub static COMPAT_LOGGER: CompatLogger = CompatLogger;
@@ -484,6 +486,38 @@ pub fn parse_logging_spec(spec: &str) -> Vec<LogDirective> {
     dirs
 }
 
+/// start the logger from config (takes RUST_LOG into account)
+pub fn setup_logging_with_config(config: &Config, tag: &str) {
+    setup_logging(
+        &config.log_target,
+        config.log_access_target.as_deref(),
+        &config.log_level,
+        tag,
+    )
+}
+
+/// start the logger, after:
+///
+/// - determining logging backends
+/// - taking RUST_LOG into account
+pub fn setup_logging(
+    log_target: &str,
+    log_access_target: Option<&str>,
+    log_level: &str,
+    tag: &str,
+) {
+    let backend = target_to_backend(log_target);
+    let access_backend = log_access_target.map(target_to_backend);
+
+    if let Ok(env_log_level) = env::var("RUST_LOG") {
+        Logger::init(tag.to_string(), &env_log_level, backend, access_backend);
+    } else {
+        // We set the env variable so every worker can access it
+        env::set_var("RUST_LOG", log_level);
+        Logger::init(tag.to_string(), log_level, backend, access_backend);
+    }
+}
+
 pub fn target_to_backend(target: &str) -> LoggerBackend {
     if target == "stdout" {
         LoggerBackend::Stdout(stdout())

e2e/src/sozu/worker.rs

@@ -1,6 +1,4 @@
 use std::{
-    env,
-    io::stdout,
     net::SocketAddr,
     os::unix::prelude::{AsRawFd, FromRawFd, IntoRawFd},
     thread::{self, JoinHandle},
@@ -15,7 +13,7 @@ use sozu::server::Server;
 use sozu_command::{
     channel::Channel,
     config::{Config, ConfigBuilder, FileConfig},
-    logging::{Logger, LoggerBackend},
+    logging::setup_logging,
     proto::command::{
         request::RequestType, AddBackend, Cluster, HardStop, LoadBalancingParams, PathRule,
         Request, RequestHttpFrontend, RequestTcpFrontend, ReturnListenSockets, RulePosition,
@@ -161,13 +159,7 @@ impl Worker {
         println!("Setting up logging");
 
         let server_job = thread::spawn(move || {
-            let log_level = env::var("RUST_LOG").unwrap_or("error".to_string());
-            Logger::init(
-                thread_name.to_owned(),
-                &log_level,
-                LoggerBackend::Stdout(stdout()),
-                None,
-            );
+            setup_logging("stdout", None, "error", &thread_name);
             let mut server = Server::try_new_from_config(
                 cmd_worker_to_main,
                 thread_scm_worker_to_main,