Merge pull request #149 from xPMo/bot-logs

Print recent logs with !bot logs

README.md

@@ -43,6 +43,7 @@ Bot management commands.
 * !bot import [module] [json object] - Update a module's settings from json (Must be done as bot owner)
 * !bot import [module] [key ...] [json object] - Update a sub-object in a module from json (Must be done as bot owner)
   * Example: !bot import alias aliases {"osm": "loc", "sh": "cmd"}
+* !bot logs [module] ([count]) - Print the [count] most recent messages the given module has reported (Must be done as bot owner)
 * !bot stats - show statistics on matrix users seen by bot
 * !bot leave - ask bot to leave this room (Must be done as admin in room)
 * !bot modules - list all modules including enabled status

bot.py

@@ -236,7 +236,16 @@ class Bot:
         :return bool: Success upon sending the message
         """
         # Sends private message to user. Returns true on success.
+        msg_room = await self.find_or_create_private_msg(mxid, roomname)
+        if not msg_room or (type(msg_room) is RoomCreateError):
+            self.logger.error(f'Unable to create room when trying to message {mxid}')
+            return False
 
+        # Send message to the room
+        await self.send_text(msg_room, message)
+        return True
+
+    async def find_or_create_private_msg(self, mxid, roomname):
         # Find if we already have a common room with user:
         msg_room = None
         for croomid in self.client.rooms:
@@ -254,14 +263,8 @@ class Bot:
                 preset=RoomPreset.private_chat,
                 invite={mxid},
             )
+        return msg_room
 
-        if not msg_room or (type(msg_room) is RoomCreateError):
-            self.logger.error(f'Unable to create room when trying to message {mxid}')
-            return False
-
-        # Send message to the room
-        await self.send_text(msg_room, message)
-        return True
 
     def remove_callback(self, callback):
         for cb_object in self.client.event_callbacks:
@@ -314,7 +317,7 @@ class Bot:
             try:
                 module_settings[modulename] = moduleobject.get_settings()
             except Exception:
-                traceback.print_exc(file=sys.stderr)
+                self.logger.exception(f'unhandled exception {modulename}.get_settings')
         data = {self.appid: self.version, 'module_settings': module_settings}
         self.set_account_data(data)
 
@@ -329,7 +332,7 @@ class Bot:
                     moduleobject.set_settings(
                         data['module_settings'][modulename])
                 except Exception:
-                    traceback.print_exc(file=sys.stderr)
+                    self.logger.exception(f'unhandled exception {modulename}.set_settings')
 
     async def message_cb(self, room, event):
         # Ignore if asked to ignore
@@ -373,7 +376,7 @@ class Bot:
                     await self.send_text(room, f'Sorry, only bot owner can run that command.')
                 except Exception:
                     await self.send_text(room, f'Module {command} experienced difficulty: {sys.exc_info()[0]} - see log for details')
-                    traceback.print_exc(file=sys.stderr)
+                    self.logger.exception(f'unhandled exception in !{command}')
         else:
             self.logger.error(f"Unknown command: {command}")
             # TODO Make this configurable
@@ -415,8 +418,7 @@ class Bot:
             cls = getattr(module, 'MatrixModule')
             return cls(modulename)
         except Exception:
-            self.logger.error(f'Module {modulename} failed to load!')
-            traceback.print_exc(file=sys.stderr)
+            self.logger.exception(f'Module {modulename} failed to load')
             return None
 
     def reload_modules(self):
@@ -446,7 +448,7 @@ class Bot:
                     try:
                         await moduleobject.matrix_poll(self, self.pollcount)
                     except Exception:
-                        traceback.print_exc(file=sys.stderr)
+                        self.logger.exception(f'unhandled exception from {modulename}.matrix_poll')
             await asyncio.sleep(10)
 
     def set_account_data(self, data):
@@ -511,7 +513,7 @@ class Bot:
                 try:
                     moduleobject.matrix_start(self)
                 except Exception:
-                    traceback.print_exc(file=sys.stderr)
+                    self.logger.exception(f'unhandled exception from {modulename}.matrix_start')
         self.logger.info(f'All modules started.')
 
     def stop(self):
@@ -520,7 +522,7 @@ class Bot:
             try:
                 moduleobject.matrix_stop(self)
             except Exception:
-                traceback.print_exc(file=sys.stderr)
+                self.logger.exception(f'unhandled exception from {modulename}.matrix_stop')
         self.logger.info(f'All modules stopped.')
 
     async def run(self):

modules/bot.py

@@ -1,11 +1,26 @@
 import collections
+import logging
 import json
 import requests
+from html import escape
 from datetime import timedelta
 import time
 
+from nio import RoomCreateError
 from modules.common.module import BotModule, ModuleCannotBeDisabled
 
+class LogDequeHandler(logging.Handler):
+    def __init__(self, count):
+        super().__init__(level = logging.NOTSET)
+        self.logs = dict()
+        self.level = logging.INFO
+
+    def emit(self, record):
+        try:
+            self.logs[str(record.module)].append(record)
+        except:
+            self.logs[str(record.module)] = collections.deque([record], maxlen=15)
+
 class MatrixModule(BotModule):
 
     def __init__(self, name):
@@ -16,6 +31,9 @@ class MatrixModule(BotModule):
     def matrix_start(self, bot):
         super().matrix_start(bot)
         self.starttime = time.time()
+        self.loghandler = LogDequeHandler(10)
+        self.loghandler.setFormatter(logging.Formatter('%(levelname)s - %(name)s - %(message)s'))
+        logging.root.addHandler(self.loghandler)
 
     async def matrix_message(self, bot, room, event):
         args = event.body.split(None, 2)
@@ -49,6 +67,8 @@ class MatrixModule(BotModule):
                 await self.export_settings(bot, event, module_name=args[2])
             elif args[1] == 'import':
                 await self.import_settings(bot, event)
+            elif args[1] == 'logs':
+                await self.last_logs(bot, room, event, args[2])
         else:
             pass
 
@@ -219,6 +239,36 @@ class MatrixModule(BotModule):
         bot.save_settings()
         await bot.send_msg(event.sender, f'Private message from {bot.matrix_user}', 'Updated bot settings')
 
+    async def last_logs(self, bot, room, event, target):
+        bot.must_be_owner(event)
+        self.logger.info(f'{event.sender} asked for recent log messages.')
+        msg_room = await bot.find_or_create_private_msg(event.sender, f'Private message from {bot.matrix_user}')
+        if not msg_room or (type(msg_room) is RoomCreateError):
+            # fallback to current room if we can't create one
+            msg_room = room
+
+        try:
+            target, count = target.split()
+            count = -abs(int(count))
+        except ValueError:
+            count = 0
+
+        keys = list(self.loghandler.logs)
+        for key in [target, f'module {target}']:
+            try:
+                logs = list(self.loghandler.logs[key])
+                break
+            except (KeyError, TypeError):
+                pass
+        else:
+            return await bot.send_text(msg_room, f'Unknown module {target}, or no logs yet')
+
+        if count:
+            logs = logs[count:]
+        logs = '\n'.join([self.loghandler.format(record) for record in logs])
+
+        return await bot.send_html(msg_room, f'<strong>Logs for {key}:</strong>\n<pre><code class="language-txt">{escape(logs)}</code></pre>', f'Logs for {key}:\n' + logs)
+
     def disable(self):
         raise ModuleCannotBeDisabled