2016-06-07 11:42:53 -04:00
|
|
|
# -*- coding: utf-8 -*-
|
2017-07-23 11:31:45 -04:00
|
|
|
import itertools
|
2016-05-08 15:32:37 -04:00
|
|
|
import logging
|
|
|
|
import re
|
2016-11-02 16:24:07 -04:00
|
|
|
from codecs import open
|
2016-06-19 16:10:35 -04:00
|
|
|
from collections import namedtuple
|
2016-05-08 15:32:37 -04:00
|
|
|
from glob import glob
|
2016-06-19 16:10:35 -04:00
|
|
|
from os.path import basename
|
2016-05-08 15:32:37 -04:00
|
|
|
|
2017-05-19 18:31:26 -04:00
|
|
|
import pendulum
|
|
|
|
|
2017-07-23 11:31:45 -04:00
|
|
|
from tsstats import events
|
|
|
|
from tsstats.client import Clients
|
2016-05-08 15:32:37 -04:00
|
|
|
|
2016-06-19 16:10:35 -04:00
|
|
|
re_log_filename = re.compile(r'ts3server_(?P<date>\d{4}-\d\d-\d\d)'
|
2018-05-19 12:06:59 -04:00
|
|
|
r'__(?P<time>\d\d_\d\d_\d\d.\d+)_(?P<sid>\d).log')
|
|
|
|
re_log_entry = re.compile(r'(?P<timestamp>\d{4}-\d\d-\d\d\ \d\d:\d\d:\d\d.\d+)'
|
|
|
|
r'\|\ *(?P<level>\w+)\ *\|\ *(?P<component>\w+)\ *'
|
|
|
|
r'\|\ *(?P<sid>\d+)\ *\|\ *(?P<message>.*)')
|
2016-10-26 18:02:56 -04:00
|
|
|
re_dis_connect = re.compile(
|
2016-10-26 18:08:28 -04:00
|
|
|
r"client (?P<action>(dis)?connected) '(?P<nick>.*)'\(id:(?P<clid>\d+)\)")
|
2016-05-08 15:32:37 -04:00
|
|
|
re_disconnect_invoker = re.compile(
|
|
|
|
r'invokername=(.*)\ invokeruid=(.*)\ reasonmsg'
|
|
|
|
)
|
|
|
|
|
2016-06-19 16:10:35 -04:00
|
|
|
TimedLog = namedtuple('TimedLog', ['path', 'timestamp'])
|
2016-11-19 16:25:57 -05:00
|
|
|
Server = namedtuple('Server', ['sid', 'clients'])
|
2016-06-19 16:10:35 -04:00
|
|
|
|
2016-05-10 16:50:34 -04:00
|
|
|
logger = logging.getLogger('tsstats')
|
|
|
|
|
|
|
|
|
2016-06-20 15:31:59 -04:00
|
|
|
def _bundle_logs(logs):
|
2016-05-30 14:23:03 -04:00
|
|
|
'''
|
2017-09-15 04:51:29 -04:00
|
|
|
Bundle `logs` by virtualserver-id
|
2016-06-20 15:31:59 -04:00
|
|
|
and sort by timestamp from filename (if exists)
|
2016-06-19 15:37:00 -04:00
|
|
|
|
2016-06-20 15:31:59 -04:00
|
|
|
:param logs: list of paths to logfiles
|
|
|
|
:type logs: list
|
2016-05-30 14:23:03 -04:00
|
|
|
|
2016-06-20 15:31:59 -04:00
|
|
|
:return: `logs` bundled by virtualserver-id and sorted by timestamp
|
2016-06-19 16:21:02 -04:00
|
|
|
:rtype: dict{str: [TimedLog]}
|
2016-05-30 14:23:03 -04:00
|
|
|
'''
|
2016-06-19 16:10:35 -04:00
|
|
|
vserver_logfiles = {} # sid: [/path/to/log1, ..., /path/to/logn]
|
2016-06-20 15:31:59 -04:00
|
|
|
for log in logs:
|
2016-06-19 16:10:35 -04:00
|
|
|
# try to get date and sid from filename
|
2016-06-20 15:31:59 -04:00
|
|
|
match = re_log_filename.match(basename(log))
|
2016-06-19 16:10:35 -04:00
|
|
|
if match:
|
|
|
|
match = match.groupdict()
|
2017-05-19 18:31:26 -04:00
|
|
|
timestamp = pendulum.parse('{0} {1}'.format(
|
|
|
|
match['date'], match['time'].replace('_', ':'))
|
|
|
|
)
|
2016-06-20 15:31:59 -04:00
|
|
|
tl = TimedLog(log, timestamp)
|
2016-06-19 16:10:35 -04:00
|
|
|
sid = match['sid']
|
|
|
|
if sid in vserver_logfiles:
|
|
|
|
# if already exists, keep list sorted by timestamp
|
2016-06-20 15:59:46 -04:00
|
|
|
vserver_logfiles[sid].append(tl)
|
2016-06-19 16:10:35 -04:00
|
|
|
vserver_logfiles[sid] =\
|
|
|
|
sorted(vserver_logfiles[sid],
|
|
|
|
key=lambda tl: tl.timestamp)
|
|
|
|
else:
|
|
|
|
# if not exists, just create a list
|
2017-03-31 16:20:43 -04:00
|
|
|
vserver_logfiles[sid] = [tl]
|
2016-06-19 16:10:35 -04:00
|
|
|
else:
|
|
|
|
# fallback to plain sorting
|
|
|
|
vserver_logfiles.setdefault('', [])\
|
2016-06-20 15:31:59 -04:00
|
|
|
.append(TimedLog(log, None))
|
2016-06-20 15:38:57 -04:00
|
|
|
vserver_logfiles[''] =\
|
|
|
|
sorted(vserver_logfiles[''],
|
|
|
|
key=lambda tl: tl.path)
|
2016-06-19 16:10:35 -04:00
|
|
|
return vserver_logfiles
|
2016-05-23 15:50:10 -04:00
|
|
|
|
2016-05-08 15:32:37 -04:00
|
|
|
|
2017-07-23 11:31:45 -04:00
|
|
|
def _parse_line(line):
|
2017-09-15 04:51:29 -04:00
|
|
|
'''
|
|
|
|
Parse events from a single line
|
|
|
|
|
|
|
|
:param line: line to parse events from
|
|
|
|
:type line: str
|
|
|
|
|
|
|
|
:return: parsed events
|
|
|
|
:rtype list
|
|
|
|
'''
|
2017-07-23 11:31:45 -04:00
|
|
|
parsed_events = []
|
|
|
|
match = re_log_entry.match(line)
|
|
|
|
if not match:
|
|
|
|
logger.debug('No match: "%s"', line)
|
|
|
|
return []
|
|
|
|
match = match.groupdict()
|
|
|
|
logdatetime = pendulum.parse(match['timestamp'])
|
|
|
|
message = match['message']
|
|
|
|
if message.startswith('client'):
|
|
|
|
match = re_dis_connect.match(message)
|
|
|
|
if not match:
|
|
|
|
logger.debug('Unsupported client action: "%s"', message)
|
|
|
|
return []
|
|
|
|
nick, clid = match.group('nick'), match.group('clid')
|
|
|
|
|
|
|
|
parsed_events.append(events.nick(logdatetime, clid, nick))
|
|
|
|
|
|
|
|
action = match.group('action')
|
|
|
|
if action == 'connected':
|
|
|
|
parsed_events.append(events.connect(logdatetime, clid))
|
|
|
|
elif action == 'disconnected':
|
|
|
|
parsed_events.append(events.disconnect(logdatetime, clid))
|
|
|
|
if 'invokeruid' in message:
|
|
|
|
re_disconnect_data = re_disconnect_invoker.findall(
|
|
|
|
message)
|
|
|
|
invokernick, invokeruid = re_disconnect_data[0]
|
|
|
|
parsed_events.append(
|
|
|
|
events.nick(logdatetime, invokeruid, invokernick)
|
|
|
|
)
|
|
|
|
if 'bantime' in message:
|
|
|
|
parsed_events.append(
|
|
|
|
events.ban(logdatetime, invokeruid, clid)
|
|
|
|
)
|
|
|
|
else:
|
|
|
|
parsed_events.append(
|
|
|
|
events.kick(logdatetime, invokeruid, clid)
|
|
|
|
)
|
2017-07-24 08:54:01 -04:00
|
|
|
return parsed_events
|
2016-06-19 15:37:00 -04:00
|
|
|
|
2016-05-30 14:23:03 -04:00
|
|
|
|
2017-09-09 12:04:29 -04:00
|
|
|
def parse_logs(log_glob, ident_map=None, online_dc=True):
|
2017-07-23 11:31:45 -04:00
|
|
|
'''
|
2017-09-15 04:51:29 -04:00
|
|
|
Parse logs from `log_glob`
|
2017-07-23 11:31:45 -04:00
|
|
|
|
|
|
|
:param log_glob: path to server-logs (supports globbing)
|
|
|
|
:param ident_map: identmap used for Client-initializations
|
2016-05-30 14:23:03 -04:00
|
|
|
|
2017-07-23 11:31:45 -04:00
|
|
|
:type log_glob: str
|
2016-05-30 14:23:03 -04:00
|
|
|
:type ident_map: dict
|
2017-08-23 15:42:08 -04:00
|
|
|
|
|
|
|
:return: list of servers
|
|
|
|
:rtype: [tsstats.log.Server]
|
2016-05-30 14:23:03 -04:00
|
|
|
'''
|
2017-07-23 11:31:45 -04:00
|
|
|
for virtualserver_id, logs in _bundle_logs(glob(log_glob)).items():
|
2016-05-24 15:48:11 -04:00
|
|
|
clients = Clients(ident_map)
|
2017-08-23 14:57:40 -04:00
|
|
|
for index, log in enumerate(logs):
|
2017-07-23 11:31:45 -04:00
|
|
|
with open(log.path, encoding='utf-8') as f:
|
2017-08-23 14:59:44 -04:00
|
|
|
logger.debug('Started parsing of %s', f.name)
|
2017-07-23 11:31:45 -04:00
|
|
|
# parse logfile line by line and filter lines without events
|
|
|
|
events = filter(None, map(_parse_line, f))
|
2018-05-19 11:28:03 -04:00
|
|
|
all_events = list(itertools.chain.from_iterable(events))
|
2017-07-23 11:31:45 -04:00
|
|
|
# chain apply events to Client-obj
|
2018-05-19 11:28:03 -04:00
|
|
|
clients.apply_events(all_events)
|
2017-08-23 14:57:40 -04:00
|
|
|
|
|
|
|
# find connected clients
|
2017-09-25 17:17:51 -04:00
|
|
|
online_clients = list(
|
|
|
|
filter(lambda c: c.connected, clients.values())
|
|
|
|
)
|
2017-08-23 14:57:40 -04:00
|
|
|
|
2018-05-02 14:58:02 -04:00
|
|
|
if online_clients:
|
|
|
|
logger.debug(
|
|
|
|
'Some clients are still connected: %s', online_clients
|
|
|
|
)
|
2018-05-19 11:28:03 -04:00
|
|
|
if index == len(logs) - 1:
|
|
|
|
if online_dc:
|
|
|
|
logger.debug(
|
|
|
|
'Last log => disconnecting online clients'
|
|
|
|
)
|
|
|
|
# last iteration
|
|
|
|
# => disconnect online clients if desired
|
|
|
|
for online_client in online_clients:
|
2023-01-14 13:02:53 -05:00
|
|
|
online_client.disconnect(pendulum.now('UTC'))
|
2018-05-19 11:28:03 -04:00
|
|
|
online_client.connected += 1
|
|
|
|
else:
|
|
|
|
logger.warn(
|
|
|
|
'Server didn\'t disconnect all clients on shutdown'
|
|
|
|
' or logfile is incorrectly named/corrupted (%s).'
|
|
|
|
' Check debuglog for details',
|
|
|
|
f.name
|
|
|
|
)
|
|
|
|
logger.debug(
|
|
|
|
'Will handle this by disconnecting all clients on'
|
|
|
|
' last event timestamp'
|
|
|
|
)
|
|
|
|
last_event_timestamp = all_events[-1].timestamp
|
|
|
|
logger.debug(
|
|
|
|
'Last event timestamp: %s', last_event_timestamp)
|
|
|
|
for online_client in online_clients:
|
|
|
|
online_client.disconnect(last_event_timestamp)
|
2017-08-23 14:59:44 -04:00
|
|
|
|
|
|
|
logger.debug('Finished parsing of %s', f.name)
|
2017-07-24 08:49:25 -04:00
|
|
|
if len(clients) >= 1:
|
|
|
|
# assemble Server-obj and yield
|
|
|
|
yield Server(virtualserver_id, clients)
|