feat(cmd-log): add cmd variant for controlling log levels (#1154)

This pull request adds a new verb called `cmd-log`. It works exactly
like `cmd`, but takes two extra arguments: `<log_level>` and
`<error_log_level>`. `<log_level>` is where command to be run, command
completion, stdout, and stderr are logged. `<error_log_level>` is where
issues running the command are logged. There are five valid levels:
`debug`, `info`, `warn`, `error`, and `none`.

This does not change the behavior or syntax of the normal `cmd`.

Example:

```
cmd-log info error bash -c "echo normal levels"
cmd-log none none bash -c "echo noisy command"
```

cfg_samples/kanata.kbd

@@ -702,6 +702,36 @@ If you need help, please feel welcome to ask in the GitHub discussions.
   ;;
   ;; cm1 (cmd bash -c "echo hello world")
   ;; cm2 (cmd rm -fr /tmp/testing)
+
+  ;; One variant of `cmd` is `cmd-log`, which lets you control how
+  ;; running command, stdout, stderr, and execution failure are logged.
+  ;;
+  ;; The command takes two extra arguments at the beginning `<log_level>`,
+  ;; and `<error_log_level>`. `<log_level>` controls where the name
+  ;; of the command is logged, as well as the success message and command 
+  ;; stdout and stderr.
+  ;;
+  ;; `<error_log_level>` is only used if there is a failure executing the initial
+  ;; command. This can be if there is trouble spawning the command, or
+  ;; the command is not found. This means if you use `bash -c "thisisntacommand"`, as
+  ;; long as bash starts up correctly, nothing would be logged to this channel, but
+  ;; something like `thisisntacommand` would be.
+  ;;
+  ;; The log level can be `debug`, `info`, `warn`, `error`, or `none`.
+  ;;
+  ;; cmd-log info error bash -c "echo these are the default levels"
+  ;; cmd-log none none bash -c "echo nothing back in kanata logs"
+  ;; cmd-log none error bash -c "only if command fails"
+  ;; cmd-log debug debug bash -c "echo log, but require changing verbosity levels"
+  ;; cmd-log warn warn bash -c "echo this probably isn't helpful"
+
+  ;; Another variant of `cmd` is `cmd-output-keys`. This reads the output
+  ;; of the command and treats it as an S-Expression, similarly to `macro`.
+  ;; However, only delays, keys, chords, and chorded lists are supported.
+  ;; Other actions are not.
+  ;; 
+  ;; bash: type date-time as YYYY-MM-DD HH:MM
+  ;; cmd-output-keys bash -c "date +'%F %R' | sed 's/./& /g' | sed 's/:/S-;/g' | sed 's/\(.\{20\}\)\(.*\)/\(\1 spc \2\)/'"
 )
 
 ;; The underscore _ means transparent. The key on the base layer will be used

docs/config.adoc

@@ -1615,6 +1615,33 @@ before the rest of your command to achieve this.
 )
 ----
 
+By default, `+cmd+` logs start of command, completion of command, stdout, and stderr. 
+Using the variant `+cmd-log+`, these log levels can be changed, and even disabled. 
+It takes two arguments, `+<log_level>+` and `+<error_log_level>+`. `+<log_level>+` 
+will be the level where the command to run, stdout, and stderr are logged. 
+The error channel is logged only if there is a failure with running the 
+command (typically if the command can't be found, or there is trouble spawning it).
+
+The valid levels are `+debug+`, `+info+`, `+warn+`, `+error+`, and `+none+`.
+
+.Example:
+[source]
+----
+(defalias
+  ;; The first two arguments are the log levels, then just the normal command
+  ;; This will only error if `bash` is not found or something else goes
+  ;; wrong with the initial execution. Any logs produced by bash will not
+  ;; be shown.
+  noisy-cmd (cmd-log none error bash -c "echo hello this produces a log")
+
+  ;; This will only log the output of the command, but it won't start
+  ;; because the command doesn't exist.
+  ignore-failure-cmd (cmd-log info none thiscmddoesnotexist)
+
+  verbose-only-log (cmd-log verbose verbose bash -c "echo yo")
+)
+----
+
 There is a variant of `cmd`: `cmd-output-keys`. This variant reads the output
 of the executed program and reads it as an S-expression, similarly to the
 <<macro, macro action>>. However — unlike macro — only delays, keys, chords, and

parser/src/cfg/list_actions.rs

@@ -85,6 +85,7 @@ pub const DYNAMIC_MACRO_RECORD: &str = "dynamic-macro-record";
 pub const DYNAMIC_MACRO_PLAY: &str = "dynamic-macro-play";
 pub const ARBITRARY_CODE: &str = "arbitrary-code";
 pub const CMD: &str = "cmd";
+pub const CMD_LOG: &str = "cmd-log";
 pub const PUSH_MESSAGE: &str = "push-msg";
 pub const CMD_OUTPUT_KEYS: &str = "cmd-output-keys";
 pub const FORK: &str = "fork";
@@ -196,6 +197,7 @@ pub fn is_list_action(ac: &str) -> bool {
         ARBITRARY_CODE,
         CMD,
         CMD_OUTPUT_KEYS,
+        CMD_LOG,
         PUSH_MESSAGE,
         FORK,
         CAPS_WORD,

parser/src/cfg/mod.rs

@@ -1692,6 +1692,7 @@ fn parse_action_list(ac: &[SExpr], s: &ParserState) -> Result<&'static KanataAct
         ARBITRARY_CODE => parse_arbitrary_code(&ac[1..], s),
         CMD => parse_cmd(&ac[1..], s, CmdType::Standard),
         CMD_OUTPUT_KEYS => parse_cmd(&ac[1..], s, CmdType::OutputKeys),
+        CMD_LOG => parse_cmd_log(&ac[1..], s),
         PUSH_MESSAGE => parse_push_message(&ac[1..], s),
         FORK => parse_fork(&ac[1..], s),
         CAPS_WORD | CAPS_WORD_A => {
@@ -2246,8 +2247,40 @@ fn parse_unicode(ac_params: &[SExpr], s: &ParserState) -> Result<&'static Kanata
 }
 
 enum CmdType {
-    Standard,
-    OutputKeys,
+    Standard,   // Execute command in own thread
+    OutputKeys, // Execute command and output stdout
+}
+
+// Parse cmd, but there are 2 arguments before specifying normal log and error log
+fn parse_cmd_log(ac_params: &[SExpr], s: &ParserState) -> Result<&'static KanataAction> {
+    const ERR_STR: &str =
+        "cmd-log expects at least 3 strings, <log-level> <error-log-level> <cmd...>";
+    if !s.is_cmd_enabled {
+        bail!("cmd is not enabled for this kanata executable (did you use 'cmd_allowed' variants?), but is set in the configuration");
+    }
+    if ac_params.len() < 3 {
+        bail!(ERR_STR);
+    }
+    let mut cmd = vec![];
+    let log_level =
+        if let Some(Ok(input_mode)) = ac_params[0].atom(s.vars()).map(LogLevel::try_from_str) {
+            input_mode
+        } else {
+            bail_expr!(&ac_params[0], "{ERR_STR}\n{}", LogLevel::err_msg());
+        };
+    let error_log_level =
+        if let Some(Ok(input_mode)) = ac_params[1].atom(s.vars()).map(LogLevel::try_from_str) {
+            input_mode
+        } else {
+            bail_expr!(&ac_params[1], "{ERR_STR}\n{}", LogLevel::err_msg());
+        };
+    collect_strings(&ac_params[2..], &mut cmd, s);
+    if cmd.is_empty() {
+        bail!(ERR_STR);
+    }
+    Ok(s.a.sref(Action::Custom(s.a.sref(
+        s.a.sref_slice(CustomAction::CmdLog(log_level, error_log_level, cmd)),
+    ))))
 }
 
 fn parse_cmd(

parser/src/cfg/tests.rs

@@ -1477,6 +1477,30 @@ fn parse_cmd() {
         .expect("parses");
 }
 
+#[test]
+#[cfg(feature = "cmd")]
+fn parse_cmd_log() {
+    let source = r#"
+(defcfg danger-enable-cmd yes)
+(defsrc a)
+(deflayer base a)
+(defvar
+    x blah
+    y (nyoom)
+    z (squish squash (splish splosh))
+)
+(defalias
+    1 (cmd-log debug debug hello world)
+    2 (cmd-log error warn (hello world))
+    3 (cmd-log info debug $x $y ($z))
+    4 (cmd-log none none hello world)
+)
+"#;
+    parse_cfg(source)
+        .map_err(|e| eprintln!("{:?}", miette::Error::from(e)))
+        .expect("parses");
+}
+
 #[test]
 fn parse_defvar_concat() {
     let _lk = lock(&CFG_PARSE_LOCK);

parser/src/custom_action.rs

@@ -12,6 +12,7 @@ use crate::{cfg::SimpleSExpr, keys::OsCode};
 #[derive(Debug, Clone, PartialEq, Eq, Hash)]
 pub enum CustomAction {
     Cmd(Vec<String>),
+    CmdLog(LogLevel, LogLevel, Vec<String>),
     CmdOutputKeys(Vec<String>),
     PushMessage(Vec<SimpleSExpr>),
     Unicode(char),
@@ -224,6 +225,49 @@ impl SequenceInputMode {
     }
 }
 
+const LOG_LEVEL_DEBUG: &str = "debug";
+const LOG_LEVEL_INFO: &str = "info";
+const LOG_LEVEL_WARN: &str = "warn";
+const LOG_LEVEL_ERROR: &str = "error";
+const LOG_LEVEL_NONE: &str = "none";
+
+#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash)]
+pub enum LogLevel {
+    // No trace here because that wouldn't make sense
+    Debug,
+    Info,
+    Warn,
+    Error,
+    None,
+}
+
+impl LogLevel {
+    pub fn try_from_str(s: &str) -> Result<Self> {
+        match s {
+            LOG_LEVEL_DEBUG => Ok(LogLevel::Debug),
+            LOG_LEVEL_INFO => Ok(LogLevel::Info),
+            LOG_LEVEL_WARN => Ok(LogLevel::Warn),
+            LOG_LEVEL_ERROR => Ok(LogLevel::Error),
+            LOG_LEVEL_NONE => Ok(LogLevel::None),
+            _ => Err(anyhow!(LogLevel::err_msg())),
+        }
+    }
+
+    pub fn get_level(&self) -> Option<log::Level> {
+        match self {
+            LogLevel::Debug => Some(log::Level::Debug),
+            LogLevel::Info => Some(log::Level::Info),
+            LogLevel::Warn => Some(log::Level::Warn),
+            LogLevel::Error => Some(log::Level::Error),
+            LogLevel::None => None,
+        }
+    }
+
+    pub fn err_msg() -> String {
+        format!("log level must be one of: {LOG_LEVEL_DEBUG}, {LOG_LEVEL_INFO}, {LOG_LEVEL_WARN}, {LOG_LEVEL_ERROR}, {LOG_LEVEL_NONE}")
+    }
+}
+
 #[derive(Debug, Clone, Copy, PartialEq, Eq, Hash)]
 pub struct UnmodMods(u8);
 

src/kanata/cmd.rs

@@ -10,7 +10,11 @@ use kanata_parser::keys::*;
 const LP: &str = "cmd-out:";
 
 #[cfg(not(feature = "simulated_output"))]
-pub(super) fn run_cmd_in_thread(cmd_and_args: Vec<String>) -> std::thread::JoinHandle<()> {
+pub(super) fn run_cmd_in_thread(
+    cmd_and_args: Vec<String>,
+    log_level: Option<log::Level>,
+    error_log_level: Option<log::Level>,
+) -> std::thread::JoinHandle<()> {
     std::thread::spawn(move || {
         let mut args = cmd_and_args.iter();
         let mut printable_cmd = String::new();
@@ -29,17 +33,31 @@ pub(super) fn run_cmd_in_thread(cmd_and_args: Vec<String>) -> std::thread::JoinH
             printable_cmd.push(' ');
             printable_cmd.push_str(arg.as_str());
         }
-        log::info!("Running cmd: {}", printable_cmd);
+        if let Some(level) = log_level {
+            log::log!(level, "Running cmd: {}", printable_cmd);
+        }
         match cmd.output() {
             Ok(output) => {
-                log::info!(
-                    "Successfully ran cmd: {}\nstdout:\n{}\nstderr:\n{}",
-                    printable_cmd,
-                    String::from_utf8_lossy(&output.stdout),
-                    String::from_utf8_lossy(&output.stderr)
-                );
+                if let Some(level) = log_level {
+                    log::log!(
+                        level,
+                        "Successfully ran cmd: {}\nstdout:\n{}\nstderr:\n{}",
+                        printable_cmd,
+                        String::from_utf8_lossy(&output.stdout),
+                        String::from_utf8_lossy(&output.stderr)
+                    );
+                };
+            }
+            Err(e) => {
+                if let Some(level) = error_log_level {
+                    log::log!(
+                        level,
+                        "Failed to execute program {:?}: {}",
+                        cmd.get_program(),
+                        e
+                    )
+                }
             }
-            Err(e) => log::error!("Failed to execute program {:?}: {}", cmd.get_program(), e),
         };
     })
 }
@@ -218,7 +236,11 @@ pub(super) fn keys_for_cmd_output(cmd_and_args: &[String]) -> impl Iterator<Item
 }
 
 #[cfg(feature = "simulated_output")]
-pub(super) fn run_cmd_in_thread(cmd_and_args: Vec<String>) -> std::thread::JoinHandle<()> {
+pub(super) fn run_cmd_in_thread(
+    cmd_and_args: Vec<String>,
+    _log_level: Option<log::Level>,
+    _error_log_level: Option<log::Level>,
+) -> std::thread::JoinHandle<()> {
     std::thread::spawn(move || {
         println!("cmd:{cmd_and_args:?}");
     })

src/kanata/mod.rs

@@ -1326,7 +1326,19 @@ impl Kanata {
                         }
                         CustomAction::Cmd(_cmd) => {
                             #[cfg(feature = "cmd")]
-                            cmds.push(_cmd.clone());
+                            cmds.push((
+                                Some(log::Level::Info),
+                                Some(log::Level::Error),
+                                _cmd.clone(),
+                            ));
+                        }
+                        CustomAction::CmdLog(_log_level, _error_log_level, _cmd) => {
+                            #[cfg(feature = "cmd")]
+                            cmds.push((
+                                _log_level.get_level(),
+                                _error_log_level.get_level(),
+                                _cmd.clone(),
+                            ));
                         }
                         CustomAction::CmdOutputKeys(_cmd) => {
                             #[cfg(feature = "cmd")]
@@ -1992,10 +2004,10 @@ fn test_unmodmods_bits() {
 }
 
 #[cfg(feature = "cmd")]
-fn run_multi_cmd(cmds: Vec<Vec<String>>) {
+fn run_multi_cmd(cmds: Vec<(Option<log::Level>, Option<log::Level>, Vec<String>)>) {
     std::thread::spawn(move || {
-        for cmd in cmds {
-            if let Err(e) = run_cmd_in_thread(cmd).join() {
+        for (cmd_log_level, cmd_error_log_level, cmd) in cmds {
+            if let Err(e) = run_cmd_in_thread(cmd, cmd_log_level, cmd_error_log_level).join() {
                 log::error!("problem joining thread {:?}", e);
             }
         }