add logging framework

paulheinr · paulheinr · commit 854b2066e8d9 · 2023-06-12T11:51:26.000+02:00
diff --git a/.cargo/config.toml b/.cargo/config.toml
@@ -1,4 +1,5 @@
 [env]
 # If you placed InertialFlowCutter in another directory, you have to set an environment variable with the corresponding path.
 # This variable has only to be set if you want to use a router.
-INERTIAL_FLOW_CUTTER_HOME_DIRECTORY= "../InertialFlowCutter"
+INERTIAL_FLOW_CUTTER_HOME_DIRECTORY="../InertialFlowCutter"
+RUST_Q_SIM_PERFORMANCE_TRACING_INTERVAL="900"
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/Cargo.toml b/Cargo.toml
@@ -25,6 +25,10 @@ prost = "0.11.5"
 bytes = "1.3.0"
 serial_test = "1.0.0"
 wait-timeout = "0.2.0"
+tracing = "0.1"
+tracing-subscriber = { version = "0.3.0", features = ["json", "fmt", "std", "registry"] }
+tracing-appender = "0.2"
+itertools = "0.10.5"
 
 [build-dependencies]
 # generates types based on .proto files
diff --git a/src/bin/mpi_qsim.rs b/src/bin/mpi_qsim.rs
@@ -1,14 +1,14 @@
 use clap::Parser;
-use log::info;
 use mpi::traits::Communicator;
 use rust_q_sim::simulation::config::Config;
 use rust_q_sim::simulation::logging;
+use tracing::info;
 
 fn main() {
     let universe = mpi::initialize().unwrap();
     let rank = universe.world().rank();
     let config = Config::parse();
-    let _logger_handle = logging::init_logging(config.output_dir.as_ref(), Some(rank.to_string()));
+    let _guards = logging::init_logging(config.output_dir.as_ref(), rank.to_string());
 
     info!("{}", mpi::environment::library_version().unwrap());
 
diff --git a/src/simulation/controller.rs b/src/simulation/controller.rs
@@ -14,7 +14,6 @@ use crate::simulation::routing::router::Router;
 use crate::simulation::routing::travel_times_collecting_road_router::TravelTimesCollectingRoadRouter;
 use crate::simulation::routing::walk_leg_updater::{EuclideanWalkLegUpdater, WalkLegUpdater};
 use crate::simulation::simulation::Simulation;
-use log::info;
 use mpi::topology::SystemCommunicator;
 use mpi::traits::{Communicator, CommunicatorCollectives};
 use std::ffi::c_int;
@@ -23,6 +22,7 @@ use std::fs::remove_dir_all;
 use std::ops::Sub;
 use std::path::PathBuf;
 use std::time::Instant;
+use tracing::info;
 
 pub fn run(world: SystemCommunicator, config: Config) {
     let rank = world.rank();
diff --git a/src/simulation/id_mapping.rs b/src/simulation/id_mapping.rs
@@ -1,10 +1,10 @@
 use crate::simulation::io::matsim_id::MatsimId;
 use crate::simulation::io::network::IONetwork;
 use crate::simulation::io::population::{IOPlanElement, IOPopulation};
-use log::info;
 use serde::{Deserialize, Serialize};
 use std::collections::HashMap;
 use std::sync::Arc;
+use tracing::info;
 
 #[derive(Debug)]
 pub struct MatsimIdMappings {
diff --git a/src/simulation/io/network.rs b/src/simulation/io/network.rs
@@ -3,14 +3,14 @@ use crate::simulation::io::matsim_id::MatsimId;
 use crate::simulation::io::xml_reader;
 use crate::simulation::network::network::Network;
 use flate2::Compression;
-use log::info;
 use quick_xml::se::to_writer;
 use serde::{Deserialize, Serialize};
 use std::fmt::Debug;
 use std::fs;
 use std::fs::File;
 use std::io::{BufWriter, Write};
 use std::path::Path;
+use tracing::info;
 
 #[derive(Debug, Deserialize, Serialize, PartialEq, Clone)]
 pub struct Attr {
diff --git a/src/simulation/io/population.rs b/src/simulation/io/population.rs
@@ -1,5 +1,5 @@
-use log::info;
 use serde::Deserialize;
+use tracing::info;
 
 use crate::simulation::io::matsim_id::MatsimId;
 use crate::simulation::io::xml_reader;
diff --git a/src/simulation/io/xml_events.rs b/src/simulation/io/xml_events.rs
@@ -1,11 +1,11 @@
 use crate::simulation::messaging::events::proto::event::Type;
 use crate::simulation::messaging::events::proto::Event;
 use crate::simulation::messaging::events::EventsSubscriber;
-use log::info;
 use std::any::Any;
 use std::fs::File;
 use std::io::{BufWriter, Write};
 use std::path::Path;
+use tracing::info;
 
 pub struct XmlEventsWriter {
     writer: BufWriter<File>,
diff --git a/src/simulation/io/xml_reader.rs b/src/simulation/io/xml_reader.rs
@@ -1,9 +1,9 @@
-use log::{debug, info};
 use quick_xml::de::from_reader;
 use serde::de::DeserializeOwned;
 use std::fs;
 use std::fs::File;
 use std::io::BufReader;
+use tracing::{debug, info};
 
 pub fn read<T>(file_path: &str) -> T
 where
diff --git a/src/simulation/logging.rs b/src/simulation/logging.rs
@@ -1,28 +1,44 @@
-use flexi_logger::{detailed_format, Duplicate, FileSpec, Logger, LoggerHandle, WriteMode};
-use log::{info, warn};
+use std::io;
+use tracing::level_filters::LevelFilter;
+use tracing::Level;
+use tracing_appender::non_blocking::WorkerGuard;
+use tracing_appender::{non_blocking, rolling};
+use tracing_subscriber::fmt;
+use tracing_subscriber::fmt::writer::MakeWriterExt;
+use tracing_subscriber::layer::SubscriberExt;
+use tracing_subscriber::Layer;
 
-pub fn init_logging(directory: &str, file_discriminant: Option<String>) -> Option<LoggerHandle> {
-    let result = Logger::try_with_str("info")
-        .unwrap()
-        .log_to_file(
-            FileSpec::default()
-                .o_discriminant(file_discriminant)
-                .suppress_timestamp()
-                .directory(directory),
-        )
-        .format(detailed_format)
-        .write_mode(WriteMode::Direct)
-        .duplicate_to_stdout(Duplicate::All)
-        .start();
+pub fn init_logging(directory: &str, file_discriminant: String) -> (WorkerGuard, WorkerGuard) {
+    let mut file_name = String::from("mpi_qsim_");
+    file_name.push_str(file_discriminant.as_str());
+
+    let log_file_appender = rolling::never(directory, &file_name);
+    let (log_file, _guard_log) = non_blocking(log_file_appender);
+
+    let mut performance_directory = String::from(directory);
+    performance_directory.push_str("/trace");
 
-    match result {
-        Ok(logger_handle) => {
-            info!("Created logger");
-            Some(logger_handle)
-        }
-        Err(_) => {
-            warn!("Was not able to create logger.");
-            None
-        }
-    }
+    let performance_file_appender = rolling::never(performance_directory, &file_name);
+    let (performance_file, _guard_performance) = non_blocking(performance_file_appender);
+
+    let collector = tracing_subscriber::registry()
+        .with(
+            fmt::Layer::new()
+                .with_writer(io::stdout)
+                .with_filter(LevelFilter::INFO),
+        )
+        .with(
+            fmt::Layer::new()
+                .with_writer(log_file)
+                .json()
+                .with_ansi(false)
+                .with_filter(LevelFilter::DEBUG),
+        )
+        .with(
+            fmt::Layer::new()
+                .with_writer(performance_file.with_min_level(Level::TRACE))
+                .json(),
+        );
+    tracing::subscriber::set_global_default(collector).expect("Unable to set a global collector");
+    (_guard_log, _guard_performance)
 }
diff --git a/src/simulation/messaging/events.rs b/src/simulation/messaging/events.rs
@@ -7,9 +7,9 @@ use crate::simulation::messaging::events::proto::{
     LinkEnterEvent, LinkLeaveEvent, PersonEntersVehicleEvent, PersonLeavesVehicleEvent,
     TravelledEvent,
 };
-use log::info;
 use std::any::Any;
 use std::collections::HashMap;
+use tracing::info;
 
 // Include the `events` module, which is generated from events.proto.
 pub mod proto {
diff --git a/src/simulation/mod.rs b/src/simulation/mod.rs
@@ -8,6 +8,7 @@ pub mod messaging;
 mod network;
 #[allow(dead_code)]
 mod partition_info;
+pub mod performance_profiling;
 mod population;
 #[allow(unused_comparisons, dead_code)]
 mod routing;
diff --git a/src/simulation/network/link.rs b/src/simulation/network/link.rs
@@ -1,7 +1,7 @@
 use std::collections::VecDeque;
 use std::fmt::Debug;
 
-use log::warn;
+use tracing::warn;
 
 use crate::simulation::io::network::IOLink;
 use crate::simulation::io::vehicle_definitions::VehicleDefinitions;
diff --git a/src/simulation/network/routing_kit_network.rs b/src/simulation/network/routing_kit_network.rs
@@ -1,6 +1,6 @@
-use log::debug;
 use rust_road_router::datastr::graph::{EdgeId, NodeId, Weight};
 use std::collections::HashMap;
+use tracing::debug;
 
 #[derive(Debug, Clone, PartialEq)]
 pub struct RoutingKitNetwork {
diff --git a/src/simulation/partition_info.rs b/src/simulation/partition_info.rs
diff --git a/src/simulation/performance_profiling/mod.rs b/src/simulation/performance_profiling/mod.rs
diff --git a/src/simulation/routing/inertial_flow_cutter_adapter.rs b/src/simulation/routing/inertial_flow_cutter_adapter.rs
diff --git a/src/simulation/routing/travel_times_collecting_road_router.rs b/src/simulation/routing/travel_times_collecting_road_router.rs
diff --git a/src/simulation/routing/travel_times_message_broker.rs b/src/simulation/routing/travel_times_message_broker.rs
diff --git a/src/simulation/simulation.rs b/src/simulation/simulation.rs
