Log filtered command name (#1631)

* Log filtered command name

If a command is blocked by a cmdfilter, the name of the command should
be logged instead of logged as "None".

* Update cmdfilter docstring

Returning cmd and args is not used by anything but for logging purposes.

* test: add tests to validate logging of cmdfilter

* docs: add info to CHANGES

---------

Co-authored-by: Sijis Aviles <sijis.aviles@gmail.com>

Author: jcfrt

CHANGES.rst

@@ -34,6 +34,7 @@ fixes:
 - chore: update Dockerfile python version (#1744)
 - chore: update errbot-backend-slackv3 version to 0.3.2 (#1743)
 - fix: allow webtest to work on python 3.13 (#1729)
+- fix: add command in logged when blocked by cmdfilter (#1631)
 
 
 v6.2.0 (2024-01-01)

errbot/__init__.py

@@ -562,7 +562,7 @@ def some_filter(self, msg, cmd, args, dry_run):
                command is authorized or not.
             \"\"\"
             # If wishing to block the incoming command:
-            return None, None, None
+            return None, cmd, args
             # Otherwise pass data through to the (potential) next filter:
             return msg, cmd, args
 

errbot/core.py

@@ -420,7 +420,7 @@ def _process_command_filters(
             for cmd_filter in self.command_filters:
                 msg, cmd, args = cmd_filter(msg, cmd, args, dry_run)
                 if msg is None:
-                    return None, None, None
+                    return None, cmd, args
             return msg, cmd, args
         except Exception:
             log.exception(
@@ -434,7 +434,7 @@ def _process_command(self, msg, cmd, args, match):
         # first it must go through the command filters
         msg, cmd, args = self._process_command_filters(msg, cmd, args, False)
         if msg is None:
-            log.info("Command %s blocked or deferred.", cmd)
+            log.info("Command \"%s\" blocked or deferred.", cmd)
             return
 
         frm = msg.frm

tests/core_test.py

@@ -1,4 +1,7 @@
-"""Test _admins_to_notify wrapper functionality"""
+"""Tests for errbot.core internals."""
+import logging
+
+from errbot.core import ErrBot
 
 extra_config = {"BOT_ADMINS_NOTIFICATIONS": "zoni@localdomain"}
 
@@ -13,3 +16,67 @@ def test_admins_not_notified(testbot):
     """Test which admins will not be notified"""
     notified_admins = testbot._bot._admins_to_notify()
     assert "gbin@local" not in notified_admins
+
+
+# --- _process_command_filters --------------------------------------------
+# Regression tests for PR #1631: when a cmdfilter blocks a command by
+# returning ``(None, cmd, args)``, the command name must propagate back to
+# the caller so it can be logged instead of "None".
+
+
+class _FilterStub:
+    """Minimal stand-in for an ErrBot exposing only what
+    ``_process_command_filters`` touches: a ``command_filters`` list."""
+
+    def __init__(self, filters):
+        self.command_filters = filters
+
+
+def _block_filter(msg, cmd, args, dry_run):
+    return None, cmd, args
+
+
+def _passthrough_filter(msg, cmd, args, dry_run):
+    return msg, cmd, args
+
+
+def _raising_filter(msg, cmd, args, dry_run):
+    raise RuntimeError("boom")
+
+
+def test_blocked_command_preserves_cmd_and_args():
+    stub = _FilterStub([_block_filter])
+    msg, cmd, args = ErrBot._process_command_filters(
+        stub, msg="hello", cmd="mycmd", args=("a", "b")
+    )
+    assert msg is None
+    assert cmd == "mycmd"
+    assert args == ("a", "b")
+
+
+def test_passthrough_filter_returns_unchanged():
+    stub = _FilterStub([_passthrough_filter])
+    msg, cmd, args = ErrBot._process_command_filters(
+        stub, msg="hello", cmd="mycmd", args=("a",)
+    )
+    assert msg == "hello"
+    assert cmd == "mycmd"
+    assert args == ("a",)
+
+
+def test_raising_filter_blocks_with_none_tuple():
+    stub = _FilterStub([_raising_filter])
+    msg, cmd, args = ErrBot._process_command_filters(
+        stub, msg="hello", cmd="mycmd", args=("a",)
+    )
+    assert (msg, cmd, args) == (None, None, None)
+
+
+def test_blocked_command_logs_cmd_name(caplog):
+    stub = _FilterStub([_block_filter])
+    with caplog.at_level(logging.INFO, logger="errbot.core"):
+        msg, cmd, args = ErrBot._process_command_filters(
+            stub, msg="hello", cmd="mycmd", args=()
+        )
+    assert msg is None
+    assert cmd == "mycmd"