From 4557498ac6cfb65add903adc0b49f1e4b7105150 Mon Sep 17 00:00:00 2001
From: projectmoon <projectmoon@agnos.is>
Date: Sat, 22 May 2021 22:17:33 +0000
Subject: [PATCH] Improved command logging, sensitive to secure commands.

---
 Cargo.lock                   | 10 ++++++++++
 Cargo.toml                   |  1 +
 src/bot/command_execution.rs | 16 ---------------
 src/commands/mod.rs          | 38 ++++++++++++++++++++++++++++++++++--
 4 files changed, 47 insertions(+), 18 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock
index 6417100..5b33f52 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -2467,6 +2467,15 @@ dependencies = [
  "unicode-normalization",
 ]
 
+[[package]]
+name = "substring"
+version = "1.4.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "42ee6433ecef213b2e72f587ef64a2f5943e7cd16fbd82dbe8bc07486c534c86"
+dependencies = [
+ "autocfg",
+]
+
 [[package]]
 name = "subtle"
 version = "2.4.0"
@@ -2548,6 +2557,7 @@ dependencies = [
  "rust-argon2",
  "serde",
  "sqlx",
+ "substring",
  "tempfile",
  "thiserror",
  "tokio",
diff --git a/Cargo.toml b/Cargo.toml
index ff312b4..8346a73 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -31,6 +31,7 @@ matrix-sdk = { git = "https://github.com/matrix-org/matrix-rust-sdk", branch = "
 refinery = { version = "0.5", features = ["rusqlite"]}
 barrel = { version = "0.6", features = ["sqlite3"] }
 tempfile = "3"
+substring = "1.4"
 
 [dependencies.sqlx]
 version = "0.5"
diff --git a/src/bot/command_execution.rs b/src/bot/command_execution.rs
index 24da3e4..9a5b5b5 100644
--- a/src/bot/command_execution.rs
+++ b/src/bot/command_execution.rs
@@ -4,7 +4,6 @@ use crate::db::sqlite::Database;
 use crate::error::BotError;
 use crate::matrix;
 use futures::stream::{self, StreamExt};
-use log::{error, info};
 use matrix_sdk::{self, identifiers::EventId, room::Joined, Client};
 use std::clone::Clone;
 
@@ -17,13 +16,6 @@ pub(super) async fn handle_single_result(
     room: &Joined,
     event_id: EventId,
 ) {
-    if cmd_result.is_err() {
-        error!(
-            "Command execution error: {}",
-            cmd_result.as_ref().err().unwrap()
-        );
-    }
-
     let html = cmd_result.message_html(respond_to);
     matrix::send_message(client, room.room_id(), &html, Some(event_id)).await;
 }
@@ -49,10 +41,6 @@ pub(super) async fn handle_multiple_results(
         })
         .collect();
 
-    for result in errors.iter() {
-        error!("Command execution error: '{}' - {}", result.0, result.1);
-    }
-
     let message = if errors.len() == 0 {
         format!("{}: Executed {} commands", respond_to, results.len())
     } else {
@@ -109,10 +97,6 @@ pub(super) async fn execute(
                 Err(e) => (command.to_owned(), Err(ExecutionError(e))),
                 Ok(ctx) => {
                     let cmd_result = execute_command(&ctx).await;
-                    info!(
-                        "[{}] {} executed: {}",
-                        ctx.room.display_name, sender, command
-                    );
                     (command.to_owned(), cmd_result)
                 }
             }
diff --git a/src/commands/mod.rs b/src/commands/mod.rs
index 631e4ad..63675b0 100644
--- a/src/commands/mod.rs
+++ b/src/commands/mod.rs
@@ -1,6 +1,7 @@
 use crate::context::Context;
 use crate::error::BotError;
 use async_trait::async_trait;
+use log::{error, info};
 use thiserror::Error;
 use BotError::DataError;
 
@@ -118,6 +119,7 @@ fn execution_allowed(cmd: &(impl Command + ?Sized), ctx: &Context<'_>) -> Result
         Ok(())
     }
 }
+
 /// Attempt to execute a command, and return the content that should
 /// go back to Matrix, if the command was executed (successfully or
 /// not). If a command is determined to be ignored, this function will
@@ -125,10 +127,42 @@ fn execution_allowed(cmd: &(impl Command + ?Sized), ctx: &Context<'_>) -> Result
 pub async fn execute_command(ctx: &Context<'_>) -> ExecutionResult {
     let cmd = parser::parse_command(&ctx.message_body)?;
 
-    match execution_allowed(cmd.as_ref(), ctx) {
+    let result = match execution_allowed(cmd.as_ref(), ctx) {
         Ok(_) => cmd.execute(ctx).await,
         Err(e) => Err(ExecutionError(e.into())),
-    }
+    };
+
+    log_command(cmd.as_ref(), ctx, &result);
+    result
+}
+
+/// Log result of an executed command.
+fn log_command(cmd: &(impl Command + ?Sized), ctx: &Context, result: &ExecutionResult) {
+    use substring::Substring;
+    let command = match cmd.is_secure() {
+        true => cmd.name(),
+        false => ctx.message_body.substring(0, 30),
+    };
+
+    let dots = match ctx.message_body.len() {
+        _len if _len > 30 => "[...]",
+        _ => "",
+    };
+
+    match result {
+        Ok(_) => {
+            info!(
+                "[{}] {} <{}{}> - success",
+                ctx.room.display_name, ctx.username, command, dots
+            );
+        }
+        Err(e) => {
+            error!(
+                "[{}] {} <{}{}> - {}",
+                ctx.room.display_name, ctx.username, command, dots, e
+            );
+        }
+    };
 }
 
 #[cfg(test)]