def __init__(self): self.rcon = Rcon(SERVER_INFO) self.rcon_2 = RecordedRcon(SERVER_INFO) self.red = get_redis_client() self.duplicate_guard_key = "unique_logs" self.log_history = self.get_log_history_list() logger.info("Registered hooks: %s", HOOKS)
def run(): # avoid circular import from rcon.extended_commands import Rcon ctl = Rcon( SERVER_INFO ) config = AutoBroadcasts() while True: msgs = config.get_messages() if not config.get_enabled() or not msgs: logger.debug("Auto broadcasts are disabled. Sleeping %s seconds", CHECK_INTERVAL) time.sleep(CHECK_INTERVAL) continue if config.get_randomize(): logger.debug("Auto broadcasts. Radomizing") random.shuffle(msgs) for time_sec, msg in msgs: if not config.get_enabled(): break formatted = format_message(ctl, msg) logger.debug("Broadcasting for %s seconds: %s", time_sec, formatted) try: ctl.set_broadcast(formatted) except CommandFailedError: logger.exception("Unable to broadcast %s", msg) time.sleep(int(time_sec))
def ban_if_blacklisted(rcon: Rcon, steam_id_64, name): with enter_session() as sess: player = get_player(sess, steam_id_64) if not player: logger.error("Can't check blacklist, player not found %s", steam_id_64) return if player.blacklist and player.blacklist.is_blacklisted: logger.info("Player %s was banned due blacklist, reason: %s", str(name), player.blacklist.reason) rcon.do_perma_ban(player=name, reason=player.blacklist.reason, admin_name=f"BLACKLIST: {player.blacklist.by}") safe_save_player_action(rcon=rcon, player_name=name, action_type="PERMABAN", reason=player.blacklist.reason, by=f"BLACKLIST: {player.blacklist.by}", steam_id_64=steam_id_64) try: send_to_discord_audit( f"`BLACKLIST` -> {dict_to_discord(dict(player=name, reason=player.blacklist.reason))}", "BLACKLIST") except: logger.error("Unable to send blacklist to audit log")
def ban_if_has_vac_bans(rcon: Rcon, steam_id_64, name): try: max_days_since_ban = int(MAX_DAYS_SINCE_BAN) max_game_bans = float('inf') if int( MAX_GAME_BAN_THRESHOLD) <= 0 else int(MAX_GAME_BAN_THRESHOLD) except ValueError: # No proper value is given logger.error( "Invalid value given for environment variable BAN_ON_VAC_HISTORY_DAYS or MAX_GAME_BAN_THRESHOLD" ) return if max_days_since_ban <= 0: return # Feature is disabled with enter_session() as sess: player = get_player(sess, steam_id_64) if not player: logger.error("Can't check VAC history, player not found %s", steam_id_64) return bans = get_player_bans(steam_id_64) if not bans or not isinstance(bans, dict): logger.warning("Can't fetch Bans for player %s, received %s", steam_id_64, bans) # Player couldn't be fetched properly (logged by get_player_bans) return if should_ban(bans, max_game_bans, max_days_since_ban): reason = AUTO_BAN_REASON.format( DAYS_SINCE_LAST_BAN=bans.get('DaysSinceLastBan'), MAX_DAYS_SINCE_BAN=str(max_days_since_ban)) logger.info( "Player %s was banned due VAC history, last ban: %s days ago", str(player), bans.get('DaysSinceLastBan')) rcon.do_perma_ban(player=name, reason=reason, admin_name="A BOT") safe_save_player_action(rcon=rcon, player_name=name, action_type="PERMABAN", reason=reason, by='AUTOBAN', steam_id_64=player.steam_id_64) try: audit_params = dict( player=name, steam_id_64=player.steam_id_64, reason=reason, days_since_last_ban=bans.get('DaysSinceLastBan'), vac_banned=bans.get('VACBanned'), number_of_game_bans=bans.get('NumberOfGameBans')) send_to_discord_audit( f"`VAC/GAME BAN` -> {dict_to_discord(audit_params)}", "AUTOBAN") except: logger.exception("Unable to send vac ban to audit log")
def event_loop(replay=False): rcon = Rcon(SERVER_INFO) last_run = 0 processed = {} logging.info("Starting map recorder thread") map_recorder = ThreadMapRecorder() map_recorder.start() logger.info("Registered hooks: %s", HOOKS) replay_time = 10 # TODO store last runtime in redis if replay: replay_time = 180 while True: since = max(min((time.time() - last_run) / 60, replay_time), 2) struct_logs = rcon.get_structured_logs(int(since)) for log in struct_logs['logs']: # Best effort to remove duplicates # We can't uniquely identify a log line because the HLL server only gives us a relative time # without giving us the server time... # The following algo assumes that within 1 minutes actions won't be repeated # This is obviously wrong as some things could be repeated, such as multiple players saying GG # within the same minute. Or even (more rarely) the same KILL combination # An alternative approach could be to use the timestamp_ms (our estimated time) with a rounding # of 50ms or so, to compensate for the time lag between the server response and our time marking # + using redis to make sure we keep the filter accross restarts if f"{log['action']}{log['message']}" in processed or abs( int(log['relative_time_ms'])) >= 60000: #logger.debug("Skipping duplicate %s", f"{log['action']}{log['message']}") continue logger.debug("Processing %s", f"{log['action']}{log['message']}") hooks = [] for action_hook, funcs in HOOKS.items(): if log['action'].startswith(action_hook): hooks += funcs for hook in hooks: try: logger.info("Triggered %s.%s on %s", hook.__module__, hook.__name__, log['raw']) hook(rcon, log) except KeyboardInterrupt: sys.exit(0) except Exception: logger.exception("Hook '%s.%s' for '%s' returned an error", hook.__module__, hook.__name__, log) processed = { f"{log['action']}{log['message']}": log['relative_time_ms'] for log in struct_logs['logs'] if abs(int(log['relative_time_ms'])) < 60000 } last_run = time.time() time.sleep(10)
def test_line(*mocks): res = Rcon.parse_logs( '[54.7 sec (1607457183)] KILL: BlAkStE(Allies/76561198202095713) -> Spaghetti with too m(Axis/76561198372886209) with Thompson' ) print(res["logs"]) assert len(res["logs"]) == 1 assert res["logs"][0]["player2"] == "Spaghetti with too m"
def test_log_parsing(*mocks): with mock.patch('rcon.extended_commands.ServerCtl.get_logs', return_value=RAW_LOGS): res = Rcon({}).get_structured_logs(30) assert set(res['actions']) == set([ 'DISCONNECTED', 'CHAT[Allies]', 'CHAT[Axis]', 'CHAT[Allies][Unit]', 'KILL', 'CONNECTED', 'CHAT[Allies][Team]', 'CHAT[Axis][Team]', 'CHAT[Axis][Unit]', 'CHAT' ]) assert set(res['players']) == set([ None, '[CPC] xALF', '湊あくあ', 'Karadoc', 'Dieter Schlüter', 'Karadoc', 'Waxxeer', 'Bullitt-FR', 'fguitou', 'bananacocoo' ]) res = Rcon({}).get_structured_logs(30, filter_action='CHAT') assert all('CHAT' in l['action'] for l in res['logs'])
def run(): rcon = Rcon(SERVER_INFO) server_number = os.getenv("SERVER_NUMBER") config = get_config(f"auto_settings_{server_number}.json") if not config: logger.warning( "No config for server number, falling back to common one") config = get_config("auto_settings.json") if not config: logger.warning( "Config 'auto_settings.json' not found. Falling back to default") config = get_config("auto_settings.default.json") if not config: logger.fatal( "Couldn't use default config 'auto_settings.default.json' exiting") exit(1) try: conditions = [ MetricCondition(name, METRICS[name], config) for name, config in config.items() ] except KeyError as e: logger.fatal("Invalid metric %s", e) exit(1) while True: for c in conditions: c.apply(rcon) time.sleep(60)
def test_chat(*mocks): res = Rcon.parse_logs( "[16:56 min (1606998360)] CHAT[Team][Zuiho(Allies/76561198088159692)]: thx" ) assert res["logs"][0]["player"] == "Zuiho" assert res["logs"][0]["sub_content"] == "thx" assert res["logs"][0]["steam_id_64_1"] == "76561198088159692" assert res["logs"][0]["action"] == "CHAT[Allies][Team]" assert res["logs"][0]["timestamp_ms"] == 1606998360000
def compare_vips(): from rcon.commands import ServerCtl from rcon.extended_commands import invalidates, Rcon rcon_2 = Rcon({"host": "176.57.171.159", "port": 28316, "password": ""}) rcon_1 = Rcon({"host": "37.187.25.13", "port": 27662, "password": ""}) with invalidates(Rcon.get_vip_ids): vip_1 = rcon_1.get_vip_ids() vip_2 = rcon_2.get_vip_ids() for vip in vip_1: if vip not in vip_2: print(vip) rcon_2.do_add_vip(name=vip["name"], steam_id_64=vip["steam_id_64"]) for vip in vip_2: if vip not in vip_1: print(vip) rcon_1.do_add_vip(name=vip["name"], steam_id_64=vip["steam_id_64"])
def test_vote(*mocks): res = Rcon.parse_logs( "[13:19 min (1606998577)] VOTE Player [nsancho] voted [PV_Favour] for VoteID[2]" ) assert res["logs"][0]["player"] == "nsancho" assert res["logs"][0]["player2"] == None # assert res['logs'][0]['sub_content'] == 'thx' assert res["logs"][0]["steam_id_64_1"] == None assert res["logs"][0]["steam_id_64_2"] == None assert res["logs"][0]["action"] == "VOTE" res = Rcon.parse_logs( "[2:34:52 hours (1607023963)] VOTE Player [DarKskiN] voted [PV_Against] for VoteID[2]" ) assert res["logs"][0]["player"] == "DarKskiN" assert res["logs"][0]["player2"] == None # assert res['logs'][0]['sub_content'] == 'thx' assert res["logs"][0]["steam_id_64_1"] == None assert res["logs"][0]["steam_id_64_2"] == None assert res["logs"][0]["action"] == "VOTE"
def run(): rcon = Rcon(SERVER_INFO) config = AutoSettingsConfig().get_settings() while True: always_apply_defaults = config.get('always_apply_defaults', False) default_commands = config.get('defaults', {}) rule_matched = False if always_apply_defaults: # First run defaults so they can be overwritten. Save "set" commands so # we prevent them from being sent more than once in the same iteration. saved_commands = { name: params for (name, params) in default_commands.items() if name.startswith('set_') } do_run_commands( rcon, { name: params for (name, params) in default_commands.items() if not name.startswith('set_') }) for rule in config['rules']: conditions = [] commands = rule.get('commands', {}) for c_name, c_params in rule.get('conditions', {}).items(): try: conditions.append(create_condition(c_name, **c_params)) except ValueError: logger.exception("Invalid condition %s %s, ignoring...", c_name, c_params) except pytz.UnknownTimeZoneError: logger.exception( "Invalid timezone for condition %s %s, ignoring...", c_name, c_params) if all([c.is_valid(rcon=rcon) for c in conditions]): if always_apply_defaults: # Overwrites the saved commands in case they're duplicate do_run_commands(rcon, {**saved_commands, **commands}) else: do_run_commands(rcon, commands) rule_matched = True break logger.info('Rule validation failed, moving to next one.') if not rule_matched: if always_apply_defaults: # The saved commands were never ran yet, so we do that here do_run_commands(rcon, saved_commands) else: do_run_commands(rcon, default_commands) time.sleep(60)
def run(): rcon = Rcon(SERVER_INFO) red = Client(connection_pool=get_redis_pool()) registered_series = [PlayerCount(red)] for series in registered_series: series.migrate() while True: for series in registered_series: series.run_on_time(rcon) time.sleep(LOOP_FREQUENCY_SEC)
def test_admin_cam_log(*mocks): res = Rcon.parse_logs( """[15:49 min (1606998428)] Player [bananacocoo (76561198003251789)] Entered Admin Camera""" ) assert res["logs"][0]["action"] == "CAMERA" assert res["logs"][0]["timestamp_ms"] == 1606998428000 assert res["logs"][0]["player"] == "bananacocoo" assert res["logs"][0]["player2"] == None # assert res['logs'][0]['sub_content'] == 'thx' assert res["logs"][0]["steam_id_64_1"] == "76561198003251789" assert res["logs"][0]["steam_id_64_2"] == None
def test_vote_started(*mocks): res = Rcon.parse_logs( "[15:49 min (1606998428)] VOTE Player [[fr]ELsass_blitz] Started a vote of type (PVR_Kick_Abuse) against [拢儿]. VoteID: [1]" ) assert res["logs"][0]["player"] == "[fr]ELsass_blitz" assert res["logs"][0]["player2"] == "拢儿" # assert res['logs'][0]['sub_content'] == 'thx' assert res["logs"][0]["steam_id_64_1"] == None assert res["logs"][0]["steam_id_64_2"] == None assert res["logs"][0]["action"] == "VOTE STARTED" assert res["logs"][0]["timestamp_ms"] == 1606998428000
def test_vote_completed(*mocks): res = Rcon.parse_logs( "[5:11 min (1606999065)] VOTE Vote [3] completed. Result: PVR_Passed") assert res["logs"][0]["player"] == None assert res["logs"][0]["player2"] == None # assert res['logs'][0]['sub_content'] == 'thx' assert res["logs"][0]["steam_id_64_1"] == None assert res["logs"][0]["steam_id_64_2"] == None assert res["logs"][0]["action"] == "VOTE COMPLETED" res = Rcon.parse_logs( "[5:11 min (1606999065)] VOTE Vote Kick {Jesse Pingman} successfully passed. [For: 2/0 - Against: 0]" ) assert res["logs"][0]["player"] == "Jesse Pingman" assert res["logs"][0]["player2"] == None # assert res['logs'][0]['sub_content'] == 'thx' assert res["logs"][0]["steam_id_64_1"] == None assert res["logs"][0]["steam_id_64_2"] == None assert res["logs"][0]["action"] == "VOTE COMPLETED"
def run(): ctl = Rcon( SERVER_INFO ) config = AutoBroadcasts() while True: msgs = config.get_messages() if not config.get_enabled() or not msgs: logger.debug("Auto broadcasts are disabled. Sleeping %s seconds", CHECK_INTERVAL) time.sleep(CHECK_INTERVAL) continue if config.get_randomize(): logger.debug("Auto broadcasts. Radomizing") random.shuffle(msgs) for time_sec, msg in msgs: subs = { 'nextmap': safe(ctl.get_next_map, "")(), 'maprotation': ' -> '.join(safe(ctl.get_map_rotation, [])()), 'servername': safe(ctl.get_name, "")(), 'onlineadmins': ', '.join(safe(ctl.get_online_admins, [])()) } formatted = msg.format(**subs) logger.debug("Broadcasting for %s seconds: %s", time_sec, formatted) ctl.set_broadcast(formatted) time.sleep(int(time_sec)) # Clear state in case next next iteration disables ctl.set_broadcast('')
def run(): rcon = Rcon(SERVER_INFO) conditions = [MetricCondition( 'player_count', lambda: PlayerCount().get_last()[1], default_commands=[('set_idle_autokick_time', {'minutes': 10}), ('set_autobalance_threshold', {'max_diff': 2}), ('set_max_ping_autokick', {'max_ms': 500}), ('set_team_switch_cooldown', {'minutes': 15})] )] while True: for c in conditions: c.apply(rcon) time.sleep(60 * 3)
def run(): max_fails = 5 from rcon.settings import SERVER_INFO recorder = MapsRecorder(Rcon(SERVER_INFO)) while True: try: recorder.detect_map_change() except CommandFailedError: logger.debug("Unable to check for map change") max_fails -= 1 if max_fails <= 0: logger.exception("Map recorder 5 failures in a row. Stopping") raise time.sleep(30)
def watchdog(rcon: Rcon, log): steam_id_64 = rcon.get_player_info(log["player"])['steam_id_64'] watcher = PlayerWatch(steam_id_64) if watcher.is_watched(): if hooks := get_prepared_watch_hooks(): watched_player = watcher.get_watch() embed = DiscordEmbed( title=f'{log["player"]} - {watched_player["steam_id_64"]}', description=f"""AKA: {", ".join(n["name"] for n in watched_player["names"])} Reason: __{watched_player['watchlist']['reason']}__ """, color=242424, ) for h in hooks: h.add_embed(embed) h.execute()
def safe(func, default=None): @wraps(func) def wrapper(*args, **kwargs): try: return func(*args, **kwargs) except: logger.exception("Unable to get data for broacasts") return default return wrapper if __name__ == '__main__': ctl = Rcon(SERVER_INFO) config = AutoBroadcasts() while True: msgs = config.get_messages() if not config.get_enabled() or not msgs: logger.debug("Auto broadcasts are disabled. Sleeping %s seconds", CHECK_INTERVAL) time.sleep(CHECK_INTERVAL) continue if config.get_randomize(): logger.debug("Auto broadcasts. Radomizing") random.shuffle(msgs)
def test_smoke_all_variables(): ctl = Rcon(SERVER_INFO) var_dict = broadcast._get_vars(ctl) for k in var_dict.keys(): print(k, broadcast.format_message(ctl, f"{'{'}{k}{'}'}"))
if self.fails > self.max_fails: raise return self.last_run_time = now return now class PlayerCount(Series): NAME = 'player_count' def __init__(self, *args, **kwargs): super().__init__(*args, **kwargs) def snapshot(self, rcon): slots = rcon.get_slots() nb, _ = slots.split('/') self.client.add(self.NAME, '*', float(nb)) if __name__ == '__main__': rcon = Rcon(SERVER_INFO) red = Client(connection_pool=get_redis_pool()) registered_series = [PlayerCount(red)] for series in registered_series: series.migrate() while True: for series in registered_series: series.run_on_time(rcon) time.sleep(LOOP_FREQUENCY_SEC)
class LogLoop: log_history_key = "log_history" def __init__(self): self.rcon = Rcon(SERVER_INFO) self.rcon_2 = RecordedRcon(SERVER_INFO) self.red = get_redis_client() self.duplicate_guard_key = "unique_logs" self.log_history = self.get_log_history_list() logger.info("Registered hooks: %s", HOOKS) @staticmethod def get_log_history_list(): return FixedLenList(key=LogLoop.log_history_key, max_len=100000) def run(self, loop_frequency_secs=5, cleanup_frequency_minutes=10): since_min = 180 self.cleanup() last_cleanup_time = datetime.datetime.now() while True: logs = self.rcon.get_structured_logs(since_min_ago=since_min) since_min = 5 for log in reversed(logs["logs"]): l = self.record_line(log) if l: self.process_hooks(l) if (datetime.datetime.now() - last_cleanup_time ).total_seconds() >= cleanup_frequency_minutes * 60: self.cleanup() last_cleanup_time = datetime.datetime.now() time.sleep(loop_frequency_secs) def record_line(self, log): id_ = f"{log['timestamp_ms']}|{log['line_without_time']}" if not self.red.sadd(self.duplicate_guard_key, id_): # logger.debug("Skipping duplicate: %s", id_) return None logger.info("Caching line: %s", id_) try: last_line = self.log_history[0] except IndexError: last_line = None if not isinstance(last_line, dict): logger.error("Can't check against last_line, invalid_format %s", last_line) elif last_line and last_line["timestamp_ms"] > log["timestamp_ms"]: logger.error("Received old log record, ignoring") return None self.log_history.add(log) return log def cleanup(self): logger.info("Starting cleanup") for k in self.red.sscan_iter(self.duplicate_guard_key): try: ts, _ = k.decode().split("|", 1) except ValueError: logger.exception("Invalid key %s", k) continue t = datetime.datetime.fromtimestamp(int(ts) / 1000) if (datetime.datetime.now() - t).total_seconds() > 280 * 60: logger.debug("Older than 180min, removing: %s", k) self.red.srem(self.duplicate_guard_key, k) logger.info("Cleanup done") def process_hooks(self, log): logger.debug("Processing %s", f"{log['action']}{log['message']}") hooks = [] for action_hook, funcs in HOOKS.items(): if log["action"].startswith(action_hook): hooks += funcs for hook in hooks: try: logger.info("Triggered %s.%s on %s", hook.__module__, hook.__name__, log["raw"]) hook(self.rcon_2, log) except KeyboardInterrupt: sys.exit(0) except Exception: logger.exception( "Hook '%s.%s' for '%s' returned an error", hook.__module__, hook.__name__, log, )
""" import os import logging from logging.config import dictConfig import sentry_sdk from sentry_sdk.integrations.django import DjangoIntegration from sentry_sdk.integrations.logging import LoggingIntegration from rcon.extended_commands import Rcon from rcon.settings import SERVER_INFO import re from sentry_sdk import configure_scope import socket try: ENVIRONMENT = re.sub('[^0-9a-zA-Z]+', '', (Rcon(SERVER_INFO).get_name() or "default").strip())[:64] except: ENVIRONMENT = "undefined" LOGGING = { 'version': 1, 'disable_existing_loggers': False, 'formatters': { 'console': { 'format': f'[%(asctime)s][%(levelname)s][{ENVIRONMENT}] %(name)s ' '%(filename)s:%(funcName)s:%(lineno)d | %(message)s', }, }, 'handlers': { 'console': { 'level': 'DEBUG',
def __init__(self): from rcon.settings import SERVER_INFO super().__init__(daemon=True) MapsRecorder.__init__(self, Rcon(SERVER_INFO))
def test_log_parsing(*mocks): with mock.patch( "rcon.extended_commands.ServerCtl.get_logs", return_value=RAW_LOGS + "\n" + RAW_VOTE, ): res = Rcon({}).get_structured_logs(30) assert set(res["actions"]) == set([ "DISCONNECTED", "CHAT[Allies]", "CHAT[Axis]", "CHAT[Allies][Unit]", "KILL", "CONNECTED", "CHAT[Allies][Team]", "CHAT[Axis][Team]", "CHAT[Axis][Unit]", "CHAT", "VOTE COMPLETED", "VOTE STARTED", "VOTE", ]) assert set(res["players"]) == set([ None, "[CPC] xALF", "湊あくあ", "Karadoc", "Dieter Schlüter: b", "Karadoc", "Waxxeer", "Bullitt-FR", "fguitou", "bananacocoo", "bananacocoo : toto", "[bananacocoo", "Codyckj", "nsancho", "拢儿", "]bananacocoo", "[ARC] MaTej ★ツ", "Cpt.Lati", "[fr]ELsass_blitz", "Galiat", "[TGF] AstroHeap", "Jesse Pingman", ]) assert set(l["timestamp_ms"] for l in res["logs"]) == { 1606999060000, 1606340677000, 1606340690000, 1606998428000, 1606998577000, 1606998429000, 1606999065000, 1606998582000, 1606999058000, 1606998434000, 1606998575000, } res = Rcon({}).get_structured_logs(30, filter_action="CHAT") assert all("CHAT" in l["action"] for l in res["logs"])
from rcon.game_logs import LogLoop from rcon.models import init_db, install_unaccent from rcon.user_config import seed_default_config from rcon.cache_utils import RedisCached, get_redis_pool from rcon.scoreboard import live_stats_loop from rcon.steam_utils import enrich_db_users logger = logging.getLogger(__name__) @click.group() def cli(): pass ctl = Rcon(SERVER_INFO) @cli.command(name="live_stats_loop") def run_stats_loop(): try: live_stats_loop() except KeyboardInterrupt: sys.exit(0) except: logger.exception("Stats loop stopped") sys.exit(1) @cli.command(name="enrich_db_users") def run_enrich_db_users():
""" import os import logging from logging.config import dictConfig import sentry_sdk from sentry_sdk.integrations.django import DjangoIntegration from sentry_sdk.integrations.logging import LoggingIntegration from rcon.extended_commands import Rcon from rcon.settings import SERVER_INFO import re from sentry_sdk import configure_scope import socket from django.utils.log import DEFAULT_LOGGING try: ENVIRONMENT = re.sub('[^0-9a-zA-Z]+', '', (Rcon(SERVER_INFO).get_name() or "default").strip())[:64] except: ENVIRONMENT = "undefined" LOGGING = { 'version': 1, 'disable_existing_loggers': False, 'formatters': { 'console': { 'format': f'[%(asctime)s][%(levelname)s][{ENVIRONMENT}] %(name)s ' '%(filename)s:%(funcName)s:%(lineno)d | %(message)s', }, }, 'handlers': {