A few minor logging enhancements (#195)

* A few minor logging enhancements

mmpy_bot/bot.py

@@ -9,6 +9,8 @@
 from mmpy_bot.settings import Settings
 from mmpy_bot.webhook_server import WebHookServer
 
+log = logging.getLogger("mmpy.bot")
+
 
 class Bot:
     """Base chatbot class.
@@ -28,12 +30,18 @@ def __init__(
         self.settings = settings or Settings()
         logging.basicConfig(
             **{
-                "format": "[%(asctime)s] %(message)s",
+                "format": self.settings.LOG_FORMAT,
                 "datefmt": "%m/%d/%Y %H:%M:%S",
                 "level": logging.DEBUG if self.settings.DEBUG else logging.INFO,
-                "stream": sys.stdout,
+                "filename": self.settings.LOG_FILE,
+                "filemode": "w",
             }
         )
+        # define and add a Handler which writes log messages to the sys.stdout
+        self.console = logging.StreamHandler(stream=sys.stdout)
+        self.console.setFormatter(logging.Formatter(self.settings.LOG_FORMAT))
+        logging.getLogger("").addHandler(self.console)
+
         self.driver = Driver(
             {
                 "url": self.settings.MATTERMOST_URL,
@@ -72,7 +80,7 @@ def _initialize_webhook_server(self):
         )
 
     def run(self):
-        logging.info(f"Starting bot {self.__class__.__name__}.")
+        log.info(f"Starting bot {self.__class__.__name__}.")
         try:
             self.running = True
 
@@ -103,7 +111,7 @@ def stop(self):
         if not self.running:
             return
 
-        logging.info("Stopping bot.")
+        log.info("Stopping bot.")
         # Shutdown the running plugins
         for plugin in self.plugins:
             plugin.on_stop()

mmpy_bot/event_handler.py

@@ -12,6 +12,8 @@
 from mmpy_bot.webhook_server import NoResponse
 from mmpy_bot.wrappers import Message, WebHookEvent
 
+log = logging.getLogger("mmpy.event_handler")
+
 
 class EventHandler(object):
     def __init__(
@@ -53,7 +55,7 @@ def _should_ignore(self, message: Message):
         ) or (self.ignore_own_messages and message.sender_name == self.driver.username)
 
     async def _check_queue_loop(self, webhook_queue: queue.Queue):
-        logging.info("EventHandlerWebHook queue listener started.")
+        log.info("EventHandlerWebHook queue listener started.")
         while True:
             try:
                 event = webhook_queue.get_nowait()

mmpy_bot/function.py

@@ -13,6 +13,8 @@
 from mmpy_bot.webhook_server import NoResponse
 from mmpy_bot.wrappers import Message, WebHookEvent
 
+log = logging.getLogger("mmpy.function")
+
 
 class Function(ABC):
     def __init__(
@@ -245,7 +247,7 @@ def ensure_response(*args):
         try:
             self.function(self.plugin, event)
         except Exception:
-            logging.exception("Exception occurred: ")
+            log.exception("Exception occurred: ")
         finally:
             return ensure_response()
 

mmpy_bot/plugins/base.py

@@ -11,6 +11,8 @@
 from mmpy_bot.settings import Settings
 from mmpy_bot.wrappers import EventWrapper, Message
 
+log = logging.getLogger("mmpy.plugin_base")
+
 
 class Plugin(ABC):
     """A Plugin is a self-contained class that defines what functions should be executed
@@ -62,15 +64,15 @@ def on_start(self):
 
         Can be overridden on the subclass if desired.
         """
-        logging.debug(f"Plugin {self.__class__.__name__} started!")
+        log.debug(f"Plugin {self.__class__.__name__} started!")
         return self
 
     def on_stop(self):
         """Will be called when the bot is shut down manually.
 
         Can be overridden on the subclass if desired.
         """
-        logging.debug(f"Plugin {self.__class__.__name__} stopped!")
+        log.debug(f"Plugin {self.__class__.__name__} stopped!")
         return self
 
     async def call_function(

mmpy_bot/settings.py

@@ -1,7 +1,7 @@
 import collections
 import os
 from dataclasses import dataclass, field, fields
-from typing import Sequence, get_args, get_origin  # type: ignore
+from typing import Optional, Sequence, get_args, get_origin  # type: ignore
 
 
 def _get_comma_separated_list(string: str, type=str):
@@ -33,6 +33,9 @@ class Settings:
     WEBHOOK_HOST_URL: str = "http://127.0.0.1"
     WEBHOOK_HOST_PORT: int = 8579
     DEBUG: bool = False
+    LOG_FILE: Optional[str] = None
+    LOG_FORMAT: str = "[%(asctime)s][%(name)s][%(levelname)s] %(message)s"
+
     IGNORE_USERS: Sequence[str] = field(default_factory=list)
     # How often to check whether any scheduled jobs need to be run, default every second
     SCHEDULER_PERIOD: float = 1.0

mmpy_bot/threadpool.py

@@ -7,6 +7,8 @@
 from mmpy_bot.scheduler import default_scheduler
 from mmpy_bot.webhook_server import WebHookServer
 
+log = logging.getLogger("mmpy.threadpool")
+
 
 class ThreadPool(object):
     def __init__(self, num_workers: int):
@@ -43,10 +45,10 @@ def stop(self):
         for _ in range(self.num_workers):
             self._queue.put((self._stop_thread, tuple()))
         # Wait for each of them to finish
-        logging.info("Stopping threadpool, waiting for threads...")
+        log.info("Stopping threadpool, waiting for threads...")
         for thread in self._threads:
             thread.join()
-        logging.info("Threadpool stopped.")
+        log.info("Threadpool stopped.")
 
     def _stop_thread(self):
         """Used to stop individual threads."""
@@ -65,22 +67,22 @@ def handle_work(self):
 
     def start_scheduler_thread(self, trigger_period: float):
         def run_pending():
-            logging.info("Scheduler thread started.")
+            log.info("Scheduler thread started.")
             while self.alive:
                 time.sleep(trigger_period)
                 default_scheduler.run_pending()
-            logging.info("Scheduler thread stopped.")
+            log.info("Scheduler thread stopped.")
 
         self.add_task(run_pending)
 
     def start_webhook_server_thread(self, webhook_server: WebHookServer):
         async def start_server():
-            logging.info("Webhook server thread started.")
+            log.info("Webhook server thread started.")
             await webhook_server.start()
             while self.alive:
                 # We just use this to keep the loop running in a non-blocking way
                 await asyncio.sleep(0.001)
             await webhook_server.stop()
-            logging.info("Webhook server thread stopped.")
+            log.info("Webhook server thread stopped.")
 
         self.add_task(asyncio.run, start_server())