diff --git a/server/area_manager.py b/server/area_manager.py index 4dc5e8e44..ead83425c 100644 --- a/server/area_manager.py +++ b/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.""" diff --git a/server/client_manager.py b/server/client_manager.py index 309d51f7e..41c7c0390 100644 --- a/server/client_manager.py +++ b/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) \ No newline at end of file diff --git a/server/commands/messaging.py b/server/commands/messaging.py index 86e0038a9..e8aef2236 100644 --- a/server/commands/messaging.py +++ b/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): diff --git a/server/commands/music.py b/server/commands/music.py index 2bfeffbad..49339e98a 100644 --- a/server/commands/music.py +++ b/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. diff --git a/server/database.py b/server/database.py index 414ba67ca..257e5d99f 100644 --- a/server/database.py +++ b/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 ?) diff --git a/server/logger.py b/server/logger.py index 117c1a8b4..34237c741 100644 --- a/server/logger.py +++ b/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 - \ No newline at end of file + 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')) diff --git a/server/network/aoprotocol.py b/server/network/aoprotocol.py index 1ef21abf2..9d6eaac2d 100644 --- a/server/network/aoprotocol.py +++ b/server/network/aoprotocol.py @@ -25,7 +25,7 @@ import asyncio import re import unicodedata - +import datetime import logging logger_debug = logging.getLogger('debug') @@ -568,7 +568,7 @@ def net_cmd_ms(self, args): self.client.last_sprite = anim self.client.flip = flip self.client.claimed_folder = folder - other_offset = '0' + other_offset = 0 other_emote = '' other_flip = 0 other_folder = '' @@ -614,8 +614,10 @@ def net_cmd_ms(self, args): ) self.client.area.set_next_msg_delay(len(msg)) - database.log_ic(self.client, self.client.area, showname, msg) - + if(bool(self.server.config['buffer_mode'])): + self.server.buffer_logger.add_to_buffer('IC', 'local', self.client, msg, showname=showname) + else: + database.log_ic(self.client, self.client.area, showname, msg) if (self.client.area.is_recording): self.client.area.recorded_messages.append(args) @@ -676,6 +678,8 @@ def net_cmd_ct(self, args): arg = spl[1][:256] try: called_function = f'ooc_cmd_{cmd}' + if cmd == 'help' and arg != '': + self.client.send_ooc(commands.help(f'ooc_cmd_{arg}')) if not hasattr(commands, called_function): self.client.send_ooc('Invalid command.') else: @@ -697,8 +701,11 @@ def net_cmd_ct(self, args): 'CT', '[' + self.client.area.abbreviation + ']' + self.client.name, args[1]) - database.log_room('ooc', self.client, - self.client.area, message=args[1]) + if(bool(self.server.config['buffer_mode'])): + self.server.buffer_logger.add_to_buffer('OOC', 'local', self.client, args[1]) + else: + database.log_room('ooc', self.client, + self.client.area, message=args[1]) def net_cmd_mc(self, args): """Play music. @@ -1015,6 +1022,8 @@ def net_cmd_zz(self, args): self.client.set_mod_call_delay() database.log_room('modcall', self.client, self.client.area, message=args[0]) + if(bool(self.server.config['buffer_mode'])): + self.server.buffer_logger.dump_log(self.client.area.abbreviation, args[0], self.client) def net_cmd_opKICK(self, args): """ diff --git a/server/tsuserver.py b/server/tsuserver.py index 4d715467a..2a96319cf 100644 --- a/server/tsuserver.py +++ b/server/tsuserver.py @@ -96,7 +96,8 @@ def __init__(self): sys.exit(1) self.client_manager = ClientManager(self) - server.logger.setup_logger(debug=self.config['debug']) + server.logger.EventLogger.setup_logger( + self, debug=self.config['debug']) def start(self): """Start the server.""" @@ -122,6 +123,9 @@ def start(self): if self.config['zalgo_tolerance']: self.zalgo_tolerance = self.config['zalgo_tolerance'] + + if self.config['buffer_mode']: + self.buffer_logger = server.logger.MessageBuffer() asyncio.ensure_future(self.schedule_unbans()) @@ -233,6 +237,8 @@ def load_config(self): self.config['modpass'] = {'default': {'password': self.config['modpass']}} if 'multiclient_limit' not in self.config: self.config['multiclient_limit'] = 16 + if 'buffer_mode' not in self.config: + self.config['buffer_mode'] = False # old behaviour is the default def load_characters(self): """Load the character list from a YAML file."""