Add a command audit log

Signed-off-by: Didier Wenzek <[email protected]>

Author: didier-wenzek

Cargo.lock

@@ -182,6 +182,7 @@ tokio-util = { version = "0.7", features = ["codec"] }
 toml = "0.8"
 tower = "0.4"
 tracing = { version = "0.1", features = ["attributes", "log"] }
+tracing-appender = "0.2"
 tracing-subscriber = { version = "0.3", features = ["time", "env-filter"] }
 try-traits = "0.1"
 tungstenite = "0.20"

Cargo.toml

@@ -35,6 +35,7 @@ tedge_utils = { workspace = true, features = ["timestamp"] }
 thiserror = { workspace = true }
 toml = { workspace = true }
 tracing = { workspace = true }
+tracing-appender = { workspace = true }
 tracing-subscriber = { workspace = true }
 url = { workspace = true }
 which = { workspace = true }

crates/common/tedge_config/Cargo.toml

@@ -5,6 +5,12 @@ use crate::system_services::SystemConfig;
 use crate::system_services::SystemServiceError;
 use std::io::IsTerminal;
 use std::str::FromStr;
+use tracing::metadata::LevelFilter;
+use tracing_appender::rolling::*;
+use tracing_subscriber::filter::filter_fn;
+use tracing_subscriber::layer::SubscriberExt;
+use tracing_subscriber::util::SubscriberInitExt;
+use tracing_subscriber::Layer;
 
 /// Configures and enables logging taking into account flags, env variables and file config.
 ///
@@ -19,7 +25,8 @@ pub fn log_init(
     flags: &LogConfigArgs,
     config_dir: &Utf8Path,
 ) -> Result<(), SystemServiceError> {
-    let subscriber = tracing_subscriber::fmt()
+    // General logging
+    let log_layer = tracing_subscriber::fmt::layer()
         .with_writer(std::io::stderr)
         .with_ansi(std::io::stderr().is_terminal())
         .with_timer(tracing_subscriber::fmt::time::UtcTime::rfc_3339());
@@ -28,22 +35,43 @@ pub fn log_init(
         .log_level
         .or(flags.debug.then_some(tracing::Level::DEBUG));
 
-    if let Some(log_level) = log_level {
-        subscriber.with_max_level(log_level).init();
-        return Ok(());
-    }
-
-    if std::env::var("RUST_LOG").is_ok() {
-        subscriber
-            .with_env_filter(tracing_subscriber::EnvFilter::from_default_env())
+    let log_layer = if let Some(log_level) = log_level {
+        log_layer
+            .with_filter(LevelFilter::from_level(log_level))
+            .boxed()
+    } else if std::env::var("RUST_LOG").is_ok() {
+        log_layer
             .with_file(true)
             .with_line_number(true)
-            .init();
-        return Ok(());
-    }
-
-    let log_level = get_log_level(sname, config_dir)?;
-    subscriber.with_max_level(log_level).init();
+            .with_filter(tracing_subscriber::EnvFilter::from_default_env())
+            .boxed()
+    } else {
+        let log_level = get_log_level(sname, config_dir)?;
+        log_layer
+            .with_filter(LevelFilter::from_level(log_level))
+            .boxed()
+    };
+
+    // Audit journal
+    let audit_appender = RollingFileAppender::builder()
+        .rotation(Rotation::DAILY)
+        .filename_prefix("tedge.audit.log")
+        .max_log_files(7);
+    let audit_layer = audit_appender
+        .build("/var/log/tedge")
+        .ok()
+        .map(|audit_appender| {
+            tracing_subscriber::fmt::layer()
+                .with_writer(audit_appender)
+                .with_timer(tracing_subscriber::fmt::time::UtcTime::rfc_3339())
+                .with_filter(LevelFilter::INFO)
+                .with_filter(filter_fn(|metadata| metadata.target() == "Audit"))
+        });
+
+    tracing_subscriber::registry()
+        .with(audit_layer)
+        .with(log_layer)
+        .init();
 
     Ok(())
 }

crates/common/tedge_config/src/system_services/log_config.rs

@@ -25,6 +25,7 @@ impl Command for AddConfigCommand {
                     .map_err(|e| e.into())
             })
             .map_err(anyhow::Error::new)?;
+        tracing::info!(target: "Audit", "tedge config add {} {}", &self.key, &self.value);
         Ok(())
     }
 }

crates/core/tedge/src/cli/config/commands/add.rs

@@ -21,6 +21,7 @@ impl Command for RemoveConfigCommand {
                     .map_err(|e| e.into())
             })
             .map_err(anyhow::Error::new)?;
+        tracing::info!(target: "Audit", "tedge config remove {} {}", &self.key, &self.value);
         Ok(())
     }
 }

crates/core/tedge/src/cli/config/commands/remove.rs

@@ -25,6 +25,7 @@ impl Command for SetConfigCommand {
                     .map_err(|e| e.into())
             })
             .map_err(anyhow::Error::new)?;
+        tracing::info!(target: "Audit", "tedge config set {} {}", &self.key, &self.value);
         Ok(())
     }
 }

crates/core/tedge/src/cli/config/commands/set.rs

@@ -17,6 +17,7 @@ impl Command for UnsetConfigCommand {
         self.config_location
             .update_toml(&|dto, _reader| Ok(dto.try_unset_key(&self.key)?))
             .map_err(anyhow::Error::new)?;
+        tracing::info!(target: "Audit", "tedge config unset {}", &self.key);
         Ok(())
     }
 }

crates/core/tedge/src/cli/config/commands/unset.rs

@@ -65,6 +65,7 @@ impl Actor for WorkflowActor {
     }
 
     async fn run(mut self) -> Result<(), RuntimeError> {
+        tracing::info!(target: "Audit", "tedge-agent started");
         self.workflow_repository.load().await;
         self.publish_operation_capabilities().await?;
         self.load_command_board().await?;
@@ -95,11 +96,15 @@ impl Actor for WorkflowActor {
                         )
                         .await
                     {
+                        tracing::info!(target: "Audit", "Updated capability {}",
+                            updated_capability.topic.as_ref(),
+                        );
                         self.mqtt_publisher.send(updated_capability).await?
                     }
                 }
             }
         }
+        tracing::info!(target: "Audit", "tedge-agent stopped");
         Ok(())
     }
 }
@@ -159,6 +164,7 @@ impl WorkflowActor {
             Ok(Some(new_state)) => {
                 self.persist_command_board().await?;
                 if new_state.is_init() {
+                    tracing::info!(target: "Audit", "Execute {operation} command, log = {}", log_file.path);
                     self.process_command_update(new_state.with_log_path(&log_file.path))
                         .await?;
                 }
@@ -211,6 +217,11 @@ impl WorkflowActor {
 
         match action {
             OperationAction::Clear => {
+                tracing::info!(
+                    target: "Audit",
+                    "{} {operation} command",
+                    if state.is_successful() {"Executed"} else { "Failed"},
+                );
                 if let Some(invoking_command) =
                     self.workflow_repository.invoking_command_state(&state)
                 {