Buffer-style message logging as an alternative to database message logging

server/area_manager.py

@@ -112,6 +112,7 @@ def remove_client(self, client):
                 self.change_status('IDLE')
             if client.char_id != -1:
                 database.log_room('area.leave', client, self)
+            self.server.area_manager.send_arup_players()
 
         def unlock(self):
             """Mark the area as unlocked."""

server/client_manager.py

@@ -625,6 +625,8 @@ def remove_client(self, client):
         for c in self.server.client_manager.clients:
             if c.ipid == temp_ipid:
                 c.clientscon -= 1
+        if client in client.area.afkers:
+            client.area.afkers.remove(client)
         self.clients.remove(client)
 
     def get_targets(self, client, key, value, local=False, single=False):
@@ -696,4 +698,4 @@ def toggle_afk(self, client):
             else:
                 client.area.broadcast_ooc('{} is now AFK.'.format(client.char_name))
                 client.send_ooc('You are now AFK. Have a good day!')
-                client.area.afkers.append(client)
+                client.area.afkers.append(client)

server/commands/messaging.py

@@ -1,3 +1,5 @@
+import arrow
+
 from server import database
 from server.constants import TargetType
 from server.exceptions import ClientError, ArgumentError, AreaError
@@ -74,7 +76,10 @@ def ooc_cmd_g(client, arg):
     if len(arg) == 0:
         raise ArgumentError("You can't send an empty message.")
     client.server.broadcast_global(client, arg)
-    database.log_room('chat.global', client, client.area, message=arg)
+    if(bool(client.server.config['buffer_mode'])):
+        client.server.buffer_logger.add_to_buffer('OOC', 'g', client, arg)
+    else:
+        database.log_room('chat.global', client, client.area, message=arg)
 
 
 @mod_only()
@@ -88,7 +93,10 @@ def ooc_cmd_gm(client, arg):
     if len(arg) == 0:
         raise ArgumentError("Can't send an empty message.")
     client.server.broadcast_global(client, arg, True)
-    database.log_room('chat.global-mod', client, client.area, message=arg)
+    if(bool(client.server.config['buffer_mode'])):
+        client.server.buffer_logger.add_to_buffer('OOC', 'gm', client, arg)
+    else:
+         database.log_room('chat.global-mod', client, client.area, message=arg)
 
 
 @mod_only()
@@ -100,7 +108,10 @@ def ooc_cmd_m(client, arg):
     if len(arg) == 0:
         raise ArgumentError("You can't send an empty message.")
     client.server.send_modchat(client, arg)
-    database.log_room('chat.mod', client, client.area, message=arg)
+    if(bool(client.server.config['buffer_mode'])):
+        client.server.buffer_logger.add_to_buffer('OOC', 'm', client, arg)
+    else:
+        database.log_room('chat.mod', client, client.area, message=arg)
 
 
 @mod_only()
@@ -114,7 +125,10 @@ def ooc_cmd_lm(client, arg):
     client.area.send_command(
         'CT', '{}[MOD][{}]'.format(client.server.config['hostname'],
                                    client.char_name), arg)
-    database.log_room('chat.local-mod', client, client.area, message=arg)
+    if(bool(client.server.config['buffer_mode'])):
+        client.server.buffer_logger.add_to_buffer('OOC', 'lm', client, arg)
+    else:
+        database.log_room('chat.local-mod', client, client.area, message=arg)
 
 
 @mod_only()
@@ -128,7 +142,10 @@ def ooc_cmd_announce(client, arg):
     client.server.send_all_cmd_pred(
         'CT', '{}'.format(client.server.config['hostname']),
         f'=== Announcement ===\r\n{arg}\r\n==================', '1')
-    database.log_room('chat.announce', client, client.area, message=arg)
+    if(bool(client.server.config['buffer_mode'])):
+        client.server.buffer_logger.add_to_buffer('OOC', 'announce', client, arg)
+    else:
+        database.log_room('chat.announce', client, client.area, message=arg)
 
 
 def ooc_cmd_toggleglobal(client, arg):

server/commands/music.py

@@ -130,7 +130,7 @@ def ooc_cmd_jukebox(client, arg):
             f'The jukebox has the following songs in it:{message}')
 
 
-@mod_only(area_owners=True)
+@mod_only()
 def ooc_cmd_play(client, arg):
     """
     Play a track.

server/database.py

@@ -1,3 +1,8 @@
+from .exceptions import ServerError
+from textwrap import dedent
+from functools import reduce
+from datetime import datetime
+from dataclasses import dataclass, field
 import os
 
 import asyncio
@@ -10,17 +15,11 @@
 logger = logging.getLogger('debug')
 event_logger = logging.getLogger('events')
 
-from dataclasses import dataclass, field
-from datetime import datetime
-from functools import reduce
-from textwrap import dedent
-
-from .exceptions import ServerError
-
 
 DB_FILE = 'storage/db.sqlite3'
 _database_singleton = None
 
+
 def __getattr__(name):
     global _database_singleton
     if _database_singleton is None:
@@ -76,7 +75,8 @@ def migrate_json_to_v1(self):
                             next_fallback_id = effective_id
                         else:
                             if effective_id != ipid:
-                                logger.debug(f'IPID {ipid} reassigned to {effective_id}')
+                                logger.debug(
+                                    f'IPID {ipid} reassigned to {effective_id}')
                             break
 
             with open('storage/hd_ids.json', 'r') as hdids_file:
@@ -86,7 +86,8 @@ def migrate_json_to_v1(self):
                         # Sometimes, there are HDID entries that do not
                         # correspond to any IPIDs in the IPID table.
                         if ipid not in ipids:
-                            logger.debug(f'IPID {ipid} in HDID list does not exist. Ignoring.')
+                            logger.debug(
+                                f'IPID {ipid} in HDID list does not exist. Ignoring.')
                             continue
                         conn.execute(dedent('''
                             INSERT OR IGNORE INTO hdids(hdid, ipid)
@@ -105,7 +106,8 @@ def migrate_json_to_v1(self):
                         logger.debug(f'Bad IPID {ipid} in ban list. Ignoring.')
                         continue
                     if ipid not in ipids:
-                        logger.debug(f'IPID {ipid} in ban list does not exist. Ignoring.')
+                        logger.debug(
+                            f'IPID {ipid} in ban list does not exist. Ignoring.')
                         continue
                     ban_id = conn.execute(dedent('''
                         INSERT INTO bans(ban_id, reason)
@@ -226,20 +228,20 @@ def ipids(self):
             """Find IPIDs affected by this ban."""
             with _database_singleton.db as conn:
                 return [row['ipid'] for row in
-                    conn.execute(dedent('''
+                        conn.execute(dedent('''
                         SELECT ipid FROM ip_bans WHERE ban_id = ?
                         '''), (self.ban_id,)).fetchall()
-                ]
+                        ]
 
         @property
         def hdids(self):
             """Find HDIDs affected by this ban."""
             with _database_singleton.db as conn:
                 return [row['hdid'] for row in
-                    conn.execute(dedent('''
+                        conn.execute(dedent('''
                         SELECT hdid FROM hdid_bans WHERE ban_id = ?
                         '''), (self.ban_id,)).fetchall()
-                ]
+                        ]
 
         @property
         def banned_by_name(self):
@@ -310,7 +312,8 @@ def _schedule_unban(self, ban_id):
             ban = conn.execute(dedent('''
                 SELECT unban_date FROM bans WHERE ban_id = ?
                 '''), (ban_id,)).fetchone()
-            time_to_unban = (arrow.get(ban['unban_date']) - arrow.utcnow()).total_seconds()
+            time_to_unban = (
+                arrow.get(ban['unban_date']) - arrow.utcnow()).total_seconds()
 
             def auto_unban():
                 self.unban(ban_id)
@@ -327,7 +330,7 @@ def log_ic(self, client, room, showname, message):
                 INSERT INTO ic_events(ipid, room_name, char_name, ic_name,
                     message) VALUES (?, ?, ?, ?, ?)
                 '''), (client.ipid, room.abbreviation, client.char_name,
-                    showname, message))
+                       showname, message))
 
     def log_room(self, event_subtype, client, room, message=None, target=None):
         """
@@ -343,14 +346,14 @@ def log_room(self, event_subtype, client, room, message=None, target=None):
             message = json.dumps(message)
 
         event_logger.info(f'[{room.abbreviation}] {client.char_name}' +
-                    f'/{client.name} ({client.ipid}): event {event_subtype} ({message})')
+                          f'/{client.name} ({client.ipid}): event {event_subtype} ({message})')
         with self.db as conn:
             conn.execute(dedent('''
                 INSERT INTO room_events(ipid, room_name, char_name, ooc_name,
                     event_subtype, message, target_ipid)
                 VALUES (?, ?, ?, ?, ?, ?, ?)
                 '''), (ipid, room.abbreviation, char_name, ooc_name,
-                    subtype_id, message, target_ipid))
+                       subtype_id, message, target_ipid))
 
     def log_connect(self, client, failed=False):
         """Log a connect attempt."""
@@ -370,7 +373,8 @@ def log_misc(self, event_subtype, client=None, target=None, data=None):
         target_ipid = target.ipid if target is not None else None
         subtype_id = self._subtype_atom('misc', event_subtype)
         data_json = json.dumps(data)
-        event_logger.info(f'{event_subtype} ({client_ipid} onto {target_ipid}): {data}')
+        event_logger.info(
+            f'{event_subtype} ({client_ipid} onto {target_ipid}): {data}')
 
         with self.db as conn:
             conn.execute(dedent('''
@@ -384,7 +388,7 @@ def recent_bans(self, count=5):
         """
         with self.db as conn:
             return [Database.Ban(**row) for row in
-                conn.execute(dedent('''
+                    conn.execute(dedent('''
                     SELECT * FROM (SELECT * FROM bans
                         WHERE ban_date IS NOT NULL
                         ORDER BY ban_date DESC LIMIT ?)

server/logger.py

@@ -20,53 +20,97 @@
 import logging
 import logging.handlers
 import time
+import arrow
+import os
 
 
-def setup_logger(debug):
+class EventLogger:
     """
-    Set up all loggers.
-    :param debug: whether debug mode should be enabled
+    Code for the event logger. Note that this is not the same as the debug logger,
+    which is a default instance of the "logging" library's logger class. This has its own
+    debug logger, which is gross and confusing. TODO: Figure out if it's even used.
+    """
+
+    def setup_logger(self, debug):
+        """
+        Set up all loggers.
+        :param debug: whether debug mode should be enabled
+
+        """
+        if not os.path.exists('logs'):
+            os.mkdir('logs')
+        logging.Formatter.converter = time.gmtime
+        debug_formatter = logging.Formatter('[%(asctime)s UTC] %(message)s')
+
+        stdoutHandler = logging.StreamHandler(sys.stdout)
+        stdoutHandler.setLevel(logging.DEBUG)
+        formatter = logging.Formatter('[%(name)s] %(module)s@%(lineno)d : %(message)s')
+        stdoutHandler.setFormatter(formatter)
+        logging.getLogger().addHandler(stdoutHandler)
+
+        debug_log = logging.getLogger('debug')
+        debug_log.setLevel(logging.DEBUG)
+
+        debug_handler = logging.handlers.RotatingFileHandler('logs/debug.log', encoding='utf-8',
+                                                                maxBytes=1024 * 1024 * 4)
+        debug_handler.setLevel(logging.DEBUG)
+        debug_handler.setFormatter(debug_formatter)
+        debug_log.addHandler(debug_handler)
+
+        # Intended to be a brief log for `tail -f`. To search through events,
+        # use the database.
+        info_log = logging.getLogger('events')
+        info_log.setLevel(logging.INFO)
+        file_handler = logging.handlers.RotatingFileHandler('logs/server.log', encoding='utf-8',
+                                                                maxBytes=1024 * 512)
+        file_handler.setFormatter(logging.Formatter('[%(asctime)s UTC] %(message)s'))
+        info_log.addHandler(file_handler)
 
+        if not debug:
+            debug_log.disabled = True
+        else:
+            debug_log.debug('Logger started')
+
+    def parse_client_info(self, client):
+        """Prepend information about a client to a log entry."""
+        if client is None:
+            return ''
+        ipid = client.ip
+        prefix = f'[{ipid:<15}][{client.id:<3}][{client.name}]'
+        if client.is_mod:
+            prefix += '[MOD]'
+        return prefix
+
+
+class MessageBuffer():
+    """
+    Represents an instance of a message buffer used for as-needed logging. This should not
+    be constructed unless the user turns on buffer mode.
     """
-    logging.Formatter.converter = time.gmtime
-    debug_formatter = logging.Formatter('[%(asctime)s UTC] %(message)s')
-
-    stdoutHandler = logging.StreamHandler(sys.stdout)
-    stdoutHandler.setLevel(logging.DEBUG)
-    formatter = logging.Formatter('[%(name)s] %(module)s@%(lineno)d : %(message)s')
-    stdoutHandler.setFormatter(formatter)
-    logging.getLogger().addHandler(stdoutHandler)
-
-    debug_log = logging.getLogger('debug')
-    debug_log.setLevel(logging.DEBUG)
-
-    debug_handler = logging.handlers.RotatingFileHandler('logs/debug.log', encoding='utf-8',
-                                                            maxBytes=1024 * 1024 * 4)
-    debug_handler.setLevel(logging.DEBUG)
-    debug_handler.setFormatter(debug_formatter)
-    debug_log.addHandler(debug_handler)
-
-    # Intended to be a brief log for `tail -f`. To search through events,
-    # use the database.
-    info_log = logging.getLogger('events')
-    info_log.setLevel(logging.INFO)
-    file_handler = logging.handlers.RotatingFileHandler('logs/server.log', encoding='utf-8',
-                                                            maxBytes=1024 * 512)
-    file_handler.setFormatter(logging.Formatter('[%(asctime)s UTC] %(message)s'))
-    info_log.addHandler(file_handler)
-
-    if not debug:
-        debug_log.disabled = True
-    else:
-        debug_log.debug('Logger started')
-
-def parse_client_info(client):
-    """Prepend information about a client to a log entry."""
-    if client is None:
-        return ''
-    ipid = client.ip
-    prefix = f'[{ipid:<15}][{client.id:<3}][{client.name}]'
-    if client.is_mod:
-        prefix += '[MOD]'
-    return prefix
-
+    buffer_counter: int
+    message_buffer: list
+
+    def __init__(self):
+        self.buffer_counter = 0
+        self.message_buffer = [None] * 501
+
+    def add_to_buffer(self, message_type, message_subtype, client, message, showname=None):
+        self.buffer_counter = (self.buffer_counter + 1) % 500
+        fullstr = (f'[{arrow.get().datetime}][{message_subtype}][{message_type}][{client.area.abbreviation}]{"[MOD]" if client.is_mod else ""} {client.char_name}/{showname if message_type == "IC" else client.name} ({client.ipid}): {message}')
+        self.message_buffer[self.buffer_counter] = fullstr
+
+    def dump_log(self, area, reason, client):
+        if not os.path.exists('reports'):
+            os.mkdir('reports')
+        with open(os.path.join('reports', str(arrow.get().datetime).replace(':', '.') + '.txt'), 'w') as f:
+            f.write(
+                f'Mod call by: {client.char_name} ({client.ipid}) aka {client.name}\n')
+            f.write('Reason: ' + reason + '\n')
+            #cheap work arounds ahoy
+            z = self.buffer_counter + 1
+            for x in range(z, 501):
+                if not self.message_buffer[x] == None and (area in self.message_buffer[x] or '[g][OOC]' in self.message_buffer[x]):
+                    f.write(str(self.message_buffer[x] + '\n'))
+            for x in range(0, z):
+                if not self.message_buffer[x] == None and (area in self.message_buffer[x] or '[g][OOC]' in self.message_buffer[x]):
+                    f.write(str(self.message_buffer[x] + '\n'))