fix(mssql): clean up module and add runtime debug logging control
- Fix indentation and lint issues - Correct message normalization and ZNC callback handling - Prevent private action logging from dereferencing missing users - Add Debug on/off/status module commands - Disable debug.log by default while keeping error.log enabled - Include debug state in Status output
This commit is contained in:
@@ -4,7 +4,6 @@ import znc
|
|||||||
import re
|
import re
|
||||||
import queue
|
import queue
|
||||||
import threading
|
import threading
|
||||||
import warnings
|
|
||||||
import traceback
|
import traceback
|
||||||
import inspect
|
import inspect
|
||||||
import os
|
import os
|
||||||
@@ -14,7 +13,7 @@ import uuid
|
|||||||
|
|
||||||
from datetime import datetime
|
from datetime import datetime
|
||||||
from time import sleep
|
from time import sleep
|
||||||
from contextlib import closing
|
|
||||||
|
|
||||||
class mssql(znc.Module):
|
class mssql(znc.Module):
|
||||||
module_types = [znc.CModInfo.GlobalModule]
|
module_types = [znc.CModInfo.GlobalModule]
|
||||||
@@ -33,15 +32,28 @@ class mssql(znc.Module):
|
|||||||
db_config = None
|
db_config = None
|
||||||
next_worker_id = 0
|
next_worker_id = 0
|
||||||
|
|
||||||
def put_log(self, code, channel, host, user, ident, user_mode, date, target_user, message, network):
|
def put_log(
|
||||||
|
self,
|
||||||
|
code,
|
||||||
|
channel,
|
||||||
|
host,
|
||||||
|
user,
|
||||||
|
ident,
|
||||||
|
user_mode,
|
||||||
|
date,
|
||||||
|
target_user,
|
||||||
|
message,
|
||||||
|
network):
|
||||||
"""
|
"""
|
||||||
Adds the log line to database write queue.
|
Adds the log line to database write queue.
|
||||||
"""
|
"""
|
||||||
|
|
||||||
decolouriser = re.compile(r"\x1f|\x02|\x1d|\x16|\x11|\x1e|\x0f|\x03(?:\d{1,2}(?:,\d{1,2})?)?|\x04(?:\d{1,2}(?:,\d{1,2})?)?", re.UNICODE)
|
decolouriser = re.compile(
|
||||||
|
r"\x1f|\x02|\x1d|\x16|\x11|\x1e|\x0f|\x03(?:\d{1,2}(?:,\d{1,2})?)?|\x04(?:\d{1,2}(?:,\d{1,2})?)?",
|
||||||
|
re.UNICODE)
|
||||||
|
|
||||||
if message is not None:
|
if message is not None:
|
||||||
message.encode('utf8', 'replace').decode('utf8')
|
message = message.encode('utf8', 'replace').decode('utf8')
|
||||||
message = decolouriser.sub("", message)
|
message = decolouriser.sub("", message)
|
||||||
|
|
||||||
if self.log_queue is None:
|
if self.log_queue is None:
|
||||||
@@ -50,7 +62,9 @@ class mssql(znc.Module):
|
|||||||
queue_len = self.log_queue.qsize() if self.log_queue is not None else 0
|
queue_len = self.log_queue.qsize() if self.log_queue is not None else 0
|
||||||
if queue_len > 10:
|
if queue_len > 10:
|
||||||
with self.internal_log.error() as target:
|
with self.internal_log.error() as target:
|
||||||
target.write('Queue length high: {} entries at {}\n'.format(queue_len, datetime.utcnow()))
|
target.write(
|
||||||
|
'Queue length high: {} entries at {}\n'.format(
|
||||||
|
queue_len, datetime.utcnow()))
|
||||||
|
|
||||||
try:
|
try:
|
||||||
self.log_queue.put({
|
self.log_queue.put({
|
||||||
@@ -69,7 +83,9 @@ class mssql(znc.Module):
|
|||||||
})
|
})
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
with self.internal_log.error() as target:
|
with self.internal_log.error() as target:
|
||||||
target.write('Failed to enqueue log event: {0} {1}\n'.format(type(e), str(e)))
|
target.write(
|
||||||
|
'Failed to enqueue log event: {0} {1}\n'.format(
|
||||||
|
type(e), str(e)))
|
||||||
target.write('Stack trace: ' + traceback.format_exc())
|
target.write('Stack trace: ' + traceback.format_exc())
|
||||||
target.write('\n')
|
target.write('\n')
|
||||||
|
|
||||||
@@ -78,7 +94,8 @@ class mssql(znc.Module):
|
|||||||
Dumps parent calling method name and its arguments to debug logfile.
|
Dumps parent calling method name and its arguments to debug logfile.
|
||||||
"""
|
"""
|
||||||
|
|
||||||
if self.hook_debugging is not True:
|
if (self.hook_debugging is not True
|
||||||
|
or not self.internal_log.debug_enabled):
|
||||||
return
|
return
|
||||||
|
|
||||||
frameinfo = inspect.stack()[1]
|
frameinfo = inspect.stack()[1]
|
||||||
@@ -89,7 +106,13 @@ class mssql(znc.Module):
|
|||||||
for argname in argvals:
|
for argname in argvals:
|
||||||
if argname == 'self':
|
if argname == 'self':
|
||||||
continue
|
continue
|
||||||
target.write(' ' + argname + ' -> ' + pprint.pformat(argvals[argname]) + '\n')
|
target.write(
|
||||||
|
' ' +
|
||||||
|
argname +
|
||||||
|
' -> ' +
|
||||||
|
pprint.pformat(
|
||||||
|
argvals[argname]) +
|
||||||
|
'\n')
|
||||||
target.write('\n')
|
target.write('\n')
|
||||||
|
|
||||||
def _start_workers(self, count):
|
def _start_workers(self, count):
|
||||||
@@ -100,16 +123,20 @@ class mssql(znc.Module):
|
|||||||
db = MSSQLDatabase(self.db_config)
|
db = MSSQLDatabase(self.db_config)
|
||||||
worker_thread = threading.Thread(
|
worker_thread = threading.Thread(
|
||||||
target=DatabaseThread.worker_safe,
|
target=DatabaseThread.worker_safe,
|
||||||
args=(db, self.log_queue, self.internal_log, self.debug_log_saves, self.batch_size),
|
args=(
|
||||||
|
db,
|
||||||
|
self.log_queue,
|
||||||
|
self.internal_log,
|
||||||
|
self.debug_log_saves,
|
||||||
|
self.batch_size),
|
||||||
daemon=True,
|
daemon=True,
|
||||||
name=f'DatabaseWorker-{idx}'
|
name=f'DatabaseWorker-{idx}')
|
||||||
)
|
|
||||||
worker_thread.start()
|
worker_thread.start()
|
||||||
self.worker_threads.append(worker_thread)
|
self.worker_threads.append(worker_thread)
|
||||||
|
|
||||||
def OnModCommand(self, command):
|
def OnModCommand(self, command):
|
||||||
"""
|
"""
|
||||||
Commands: Status, AddWorkers <n>
|
Commands: Status, AddWorkers <n>, Debug [on|off|status]
|
||||||
"""
|
"""
|
||||||
parts = str(command).split()
|
parts = str(command).split()
|
||||||
if not parts:
|
if not parts:
|
||||||
@@ -117,9 +144,16 @@ class mssql(znc.Module):
|
|||||||
cmd = parts[0].lower()
|
cmd = parts[0].lower()
|
||||||
|
|
||||||
if cmd == 'status':
|
if cmd == 'status':
|
||||||
alive = len([t for t in self.worker_threads if t.is_alive()]) if self.worker_threads else 0
|
alive = len([t for t in self.worker_threads if t.is_alive()]
|
||||||
|
) if self.worker_threads else 0
|
||||||
qsize = self.log_queue.qsize() if self.log_queue is not None else 0
|
qsize = self.log_queue.qsize() if self.log_queue is not None else 0
|
||||||
self.PutModule('Workers alive: {}, queue length: {}, batch size: {}'.format(alive, qsize, self.batch_size))
|
self.PutModule(
|
||||||
|
'Workers alive: {}, queue length: {}, batch size: {}, '
|
||||||
|
'debug: {}'.format(
|
||||||
|
alive,
|
||||||
|
qsize,
|
||||||
|
self.batch_size,
|
||||||
|
'on' if self.internal_log.debug_enabled else 'off'))
|
||||||
elif cmd == 'addworkers':
|
elif cmd == 'addworkers':
|
||||||
try:
|
try:
|
||||||
n = int(parts[1])
|
n = int(parts[1])
|
||||||
@@ -129,12 +163,30 @@ class mssql(znc.Module):
|
|||||||
current = len(self.worker_threads)
|
current = len(self.worker_threads)
|
||||||
n = max(0, min(n, self.max_workers - current))
|
n = max(0, min(n, self.max_workers - current))
|
||||||
if n == 0:
|
if n == 0:
|
||||||
self.PutModule('No workers added (limit is {}, currently {})'.format(self.max_workers, current))
|
self.PutModule(
|
||||||
|
'No workers added (limit is {}, currently {})'.format(
|
||||||
|
self.max_workers, current))
|
||||||
return
|
return
|
||||||
self._start_workers(n)
|
self._start_workers(n)
|
||||||
self.PutModule('Started {} workers, now {}'.format(n, len(self.worker_threads)))
|
self.PutModule(
|
||||||
|
'Started {} workers, now {}'.format(
|
||||||
|
n, len(
|
||||||
|
self.worker_threads)))
|
||||||
|
elif cmd == 'debug':
|
||||||
|
setting = parts[1].lower() if len(parts) > 1 else 'status'
|
||||||
|
if setting == 'status':
|
||||||
|
state = 'on' if self.internal_log.debug_enabled else 'off'
|
||||||
|
self.PutModule('Debug logging is {}'.format(state))
|
||||||
|
elif setting in ('on', 'off'):
|
||||||
|
enabled = setting == 'on'
|
||||||
|
self.internal_log.set_debug_enabled(enabled)
|
||||||
|
self.PutModule('Debug logging {}'.format(
|
||||||
|
'enabled' if enabled else 'disabled'))
|
||||||
else:
|
else:
|
||||||
self.PutModule('Commands: Status, AddWorkers <n>')
|
self.PutModule('Usage: Debug [on|off|status]')
|
||||||
|
else:
|
||||||
|
self.PutModule(
|
||||||
|
'Commands: Status, AddWorkers <n>, Debug [on|off|status]')
|
||||||
|
|
||||||
def OnLoad(self, args, message):
|
def OnLoad(self, args, message):
|
||||||
"""
|
"""
|
||||||
@@ -157,18 +209,26 @@ class mssql(znc.Module):
|
|||||||
self.num_workers = self.max_workers
|
self.num_workers = self.max_workers
|
||||||
except (ValueError, AttributeError, TypeError) as e:
|
except (ValueError, AttributeError, TypeError) as e:
|
||||||
with self.internal_log.debug() as target:
|
with self.internal_log.debug() as target:
|
||||||
target.write('Failed to parse args: {} (args_str: "{}", type: {})\n'.format(e, args_str, type(args)))
|
target.write(
|
||||||
|
'Failed to parse args: {} (args_str: "{}", type: {})\n'.format(
|
||||||
|
e, args_str, type(args)))
|
||||||
|
|
||||||
with self.internal_log.debug() as target:
|
with self.internal_log.debug() as target:
|
||||||
target.write('mssql module loaded at: {}\n'.format(datetime.utcnow()))
|
target.write(
|
||||||
|
'mssql module loaded at: {}\n'.format(
|
||||||
|
datetime.utcnow()))
|
||||||
target.write('save_path: {}\n'.format(self.GetSavePath()))
|
target.write('save_path: {}\n'.format(self.GetSavePath()))
|
||||||
target.write('raw args: {} (type: {})\n'.format(repr(args), type(args).__name__))
|
target.write(
|
||||||
|
'raw args: {} (type: {})\n'.format(
|
||||||
|
repr(args), type(args).__name__))
|
||||||
target.write('parsed args_str: "{}"\n'.format(args_str))
|
target.write('parsed args_str: "{}"\n'.format(args_str))
|
||||||
target.write('num_workers: {}\n'.format(self.num_workers))
|
target.write('num_workers: {}\n'.format(self.num_workers))
|
||||||
target.write('\n')
|
target.write('\n')
|
||||||
|
|
||||||
with self.internal_log.error() as target:
|
with self.internal_log.error() as target:
|
||||||
target.write('mssql module loaded at: {}\n'.format(datetime.utcnow()))
|
target.write(
|
||||||
|
'mssql module loaded at: {}\n'.format(
|
||||||
|
datetime.utcnow()))
|
||||||
target.write('hook_debugging: {}\n'.format(self.hook_debugging))
|
target.write('hook_debugging: {}\n'.format(self.hook_debugging))
|
||||||
target.write('num_workers: {}\n'.format(self.num_workers))
|
target.write('num_workers: {}\n'.format(self.num_workers))
|
||||||
target.write('\n')
|
target.write('\n')
|
||||||
@@ -195,19 +255,22 @@ class mssql(znc.Module):
|
|||||||
message.s = str(e)
|
message.s = str(e)
|
||||||
|
|
||||||
with self.internal_log.error() as target:
|
with self.internal_log.error() as target:
|
||||||
target.write('Could not initialize module caused by: {} {}\n'.format(type(e), str(e)))
|
target.write(
|
||||||
|
'Could not initialize module caused by: {} {}\n'.format(
|
||||||
|
type(e), str(e)))
|
||||||
target.write('Stack trace: ' + traceback.format_exc())
|
target.write('Stack trace: ' + traceback.format_exc())
|
||||||
target.write('\n')
|
target.write('\n')
|
||||||
|
|
||||||
return False
|
return False
|
||||||
|
|
||||||
|
|
||||||
def OnUnload(self):
|
def OnUnload(self):
|
||||||
if self.log_queue is None:
|
if self.log_queue is None:
|
||||||
return
|
return
|
||||||
|
|
||||||
with self.internal_log.debug() as target:
|
with self.internal_log.debug() as target:
|
||||||
target.write('Unloading module, draining queue length {}\n'.format(self.log_queue.qsize()))
|
target.write(
|
||||||
|
'Unloading module, draining queue length {}\n'.format(
|
||||||
|
self.log_queue.qsize()))
|
||||||
|
|
||||||
# Send one sentinel value per worker thread
|
# Send one sentinel value per worker thread
|
||||||
if self.worker_threads:
|
if self.worker_threads:
|
||||||
@@ -240,7 +303,8 @@ class mssql(znc.Module):
|
|||||||
:rtype: None
|
:rtype: None
|
||||||
"""
|
"""
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("CONNECT", None, None, None, None, None, datetime.now(), None, None, str(self.GetNetwork()))
|
self.put_log("CONNECT", None, None, None, None, None,
|
||||||
|
datetime.now(), None, None, str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnIRCDisconnected(self):
|
def OnIRCDisconnected(self):
|
||||||
@@ -249,12 +313,22 @@ class mssql(znc.Module):
|
|||||||
:rtype: None
|
:rtype: None
|
||||||
"""
|
"""
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("DISCONNECT", None, None, None, None, None, datetime.now(), None, None, str(self.GetNetwork()))
|
self.put_log("DISCONNECT", None, None, None, None, None,
|
||||||
|
datetime.now(), None, None, str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnOp(self, user, target_user, channel, noChange):
|
def OnOp(self, user, target_user, channel, noChange):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("OP", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), target_user.GetNick(), None, str(self.GetNetwork()))
|
self.put_log("OP",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
target_user.GetNick(),
|
||||||
|
None,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnChanNotice(self, nick, channel, message):
|
def OnChanNotice(self, nick, channel, message):
|
||||||
@@ -266,12 +340,30 @@ class mssql(znc.Module):
|
|||||||
:rtype: EModRet
|
:rtype: EModRet
|
||||||
"""
|
"""
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("NOTICE", channel.GetName(), nick.GetHost(), nick.GetNick(), nick.GetIdent(), None, datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("NOTICE",
|
||||||
|
channel.GetName(),
|
||||||
|
nick.GetHost(),
|
||||||
|
nick.GetNick(),
|
||||||
|
nick.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnPrivNotice(self, user, message):
|
def OnPrivNotice(self, user, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("NOTICE", None, user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("NOTICE",
|
||||||
|
None,
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnUserNotice(self, target, message):
|
def OnUserNotice(self, target, message):
|
||||||
@@ -284,21 +376,58 @@ class mssql(znc.Module):
|
|||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
network = self.GetNetwork()
|
network = self.GetNetwork()
|
||||||
if network:
|
if network:
|
||||||
self.put_log("NOTICE", None, target.GetHost(), target.GetNick(), target.GetIdent(), None, datetime.now(), target.GetNick(), message, str(self.GetNetwork()))
|
self.put_log("NOTICE",
|
||||||
|
None,
|
||||||
|
target.GetHost(),
|
||||||
|
target.GetNick(),
|
||||||
|
target.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
target.GetNick(),
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnDeop(self, user, target_user, channel, noChange):
|
def OnDeop(self, user, target_user, channel, noChange):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("DEOP", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), target_user.GetNick(), None, str(self.GetNetwork()))
|
self.put_log("DEOP",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
target_user.GetNick(),
|
||||||
|
None,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnVoice(self, user, target_user, channel, noChange):
|
def OnVoice(self, user, target_user, channel, noChange):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("VOICE", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), target_user.GetNick(), None, str(self.GetNetwork()))
|
self.put_log("VOICE",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
target_user.GetNick(),
|
||||||
|
None,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnDevoice(self, user, target_user, channel, noChange):
|
def OnDevoice(self, user, target_user, channel, noChange):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("DEVOICE", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), target_user.GetNick(), None, str(self.GetNetwork()))
|
self.put_log("DEVOICE",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
target_user.GetNick(),
|
||||||
|
None,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnMode(self, user, channel, mode, argument, added, noChange):
|
def OnMode(self, user, channel, mode, argument, added, noChange):
|
||||||
@@ -311,41 +440,107 @@ class mssql(znc.Module):
|
|||||||
sign = "+" if added else "-"
|
sign = "+" if added else "-"
|
||||||
argument = "{0}{1} {2}".format(sign, mode, argument)
|
argument = "{0}{1} {2}".format(sign, mode, argument)
|
||||||
|
|
||||||
self.put_log(code, channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, argument, str(self.GetNetwork()))
|
self.put_log(code,
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
argument,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnQuit(self, user, message, channels):
|
def OnQuit(self, user, message, channels):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
for channel in channels:
|
for channel in channels:
|
||||||
self.put_log("QUIT", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, message, str(self.GetNetwork()))
|
self.put_log("QUIT",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnNick(self, user, new_nick, channels):
|
def OnNick(self, user, new_nick, channels):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
for channel in channels:
|
for channel in channels:
|
||||||
self.put_log("NICK", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), new_nick, None, str(self.GetNetwork()))
|
self.put_log("NICK",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
new_nick,
|
||||||
|
None,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnKick(self, user, target_nick, channel, message):
|
def OnKick(self, user, target_nick, channel, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("KICK", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), target_nick, message, str(self.GetNetwork()))
|
self.put_log("KICK",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
target_nick,
|
||||||
|
message,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnJoin(self, user, channel):
|
def OnJoin(self, user, channel):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("JOIN", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, None, str(self.GetNetwork()))
|
self.put_log("JOIN",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
None,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnPart(self, user, channel, message):
|
def OnPart(self, user, channel, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("PART", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, message, str(self.GetNetwork()))
|
self.put_log("PART",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnUserAction (self, target, message):
|
def OnUserAction(self, target, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
(channel, user) = self.resolveTarget(target)
|
(channel, user) = self.resolveTarget(target)
|
||||||
if channel == None:
|
if channel is None:
|
||||||
self.put_log("ME", None, user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, message, str(self.GetNetwork()))
|
local_nick = self.GetNetwork().GetIRCNick()
|
||||||
|
self.put_log(
|
||||||
|
"ME",
|
||||||
|
None,
|
||||||
|
local_nick.GetHost() if local_nick is not None else None,
|
||||||
|
local_nick.GetNick() if local_nick is not None else None,
|
||||||
|
local_nick.GetIdent() if local_nick is not None else None,
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
target.s,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()),
|
||||||
|
)
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
return self.OnChanAction(user, channel, message)
|
return self.OnChanAction(user, channel, message)
|
||||||
|
|
||||||
@@ -357,22 +552,58 @@ class mssql(znc.Module):
|
|||||||
:rtype: EModRet
|
:rtype: EModRet
|
||||||
"""
|
"""
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("ME", None, nick.GetHost(), nick.GetNick(), nick.GetIdent(), None, datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("ME",
|
||||||
|
None,
|
||||||
|
nick.GetHost(),
|
||||||
|
nick.GetNick(),
|
||||||
|
nick.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnPrivMsg(self, nick, message):
|
def OnPrivMsg(self, nick, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("MSG", None, nick.GetHost(), nick.GetNick(), nick.GetIdent(), None, datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("MSG",
|
||||||
|
None,
|
||||||
|
nick.GetHost(),
|
||||||
|
nick.GetNick(),
|
||||||
|
nick.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnPrivCTCP(self, nick, message):
|
def OnPrivCTCP(self, nick, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("CTCP", None, nick.GetHost(), nick.GetNick(), nick.GetIdent(), None, datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("CTCP",
|
||||||
|
None,
|
||||||
|
nick.GetHost(),
|
||||||
|
nick.GetNick(),
|
||||||
|
nick.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnChanCTCP(self, user, channel, message):
|
def OnChanCTCP(self, user, channel, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("CTCP", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("CTCP",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnUserCTCP(self, target, message):
|
def OnUserCTCP(self, target, message):
|
||||||
@@ -406,10 +637,10 @@ class mssql(znc.Module):
|
|||||||
)
|
)
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnUserMsg (self, target, message):
|
def OnUserMsg(self, target, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
(channel, user) = self.resolveTarget(target)
|
(channel, user) = self.resolveTarget(target)
|
||||||
if channel == None:
|
if channel is None:
|
||||||
local_nick = self.GetNetwork().GetIRCNick()
|
local_nick = self.GetNetwork().GetIRCNick()
|
||||||
if local_nick is not None:
|
if local_nick is not None:
|
||||||
self.put_log(
|
self.put_log(
|
||||||
@@ -442,17 +673,45 @@ class mssql(znc.Module):
|
|||||||
|
|
||||||
def OnChanAction(self, user, channel, message):
|
def OnChanAction(self, user, channel, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("ME", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("ME",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return True
|
return True
|
||||||
|
|
||||||
def OnChanMsg(self, user, channel, message):
|
def OnChanMsg(self, user, channel, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("SAY", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), self.findMode(channel, user), datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("SAY",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
self.findMode(channel,
|
||||||
|
user),
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def OnTopic(self, user, channel, message):
|
def OnTopic(self, user, channel, message):
|
||||||
self.debug_hook()
|
self.debug_hook()
|
||||||
self.put_log("TOPIC", channel.GetName(), user.GetHost(), user.GetNick(), user.GetIdent(), None, datetime.now(), None, message.s, str(self.GetNetwork()))
|
self.put_log("TOPIC",
|
||||||
|
channel.GetName(),
|
||||||
|
user.GetHost(),
|
||||||
|
user.GetNick(),
|
||||||
|
user.GetIdent(),
|
||||||
|
None,
|
||||||
|
datetime.now(),
|
||||||
|
None,
|
||||||
|
message.s,
|
||||||
|
str(self.GetNetwork()))
|
||||||
return znc.CONTINUE
|
return znc.CONTINUE
|
||||||
|
|
||||||
def findMode(self, channel, user):
|
def findMode(self, channel, user):
|
||||||
@@ -464,7 +723,7 @@ class mssql(znc.Module):
|
|||||||
def resolveTarget(self, target):
|
def resolveTarget(self, target):
|
||||||
target = target.s
|
target = target.s
|
||||||
channel = self.GetNetwork().FindChan(target)
|
channel = self.GetNetwork().FindChan(target)
|
||||||
if channel == None:
|
if channel is None:
|
||||||
return (None, None)
|
return (None, None)
|
||||||
user = self.GetNetwork().GetIRCNick()
|
user = self.GetNetwork().GetIRCNick()
|
||||||
return (channel, user)
|
return (channel, user)
|
||||||
@@ -473,60 +732,77 @@ class mssql(znc.Module):
|
|||||||
find = data.find('\x03')
|
find = data.find('\x03')
|
||||||
while find > -1:
|
while find > -1:
|
||||||
done = False
|
done = False
|
||||||
data = data[0:find] + data[find+1:]
|
data = data[0:find] + data[find + 1:]
|
||||||
if len(data) <= find+1:
|
if len(data) <= find + 1:
|
||||||
done = True
|
done = True
|
||||||
try:
|
try:
|
||||||
assert not done
|
assert not done
|
||||||
assert int(data[find])
|
assert int(data[find])
|
||||||
while True:
|
while True:
|
||||||
assert int(data[find])
|
assert int(data[find])
|
||||||
data = data[0:find] + data[find+1:]
|
data = data[0:find] + data[find + 1:]
|
||||||
except:
|
except BaseException:
|
||||||
if not done:
|
if not done:
|
||||||
if data[find] != ',': done = True
|
if data[find] != ',':
|
||||||
|
done = True
|
||||||
|
|
||||||
if (not done) and (len(data) > find+1) and (data[find] == ','):
|
if (not done) and (len(data) > find + 1) and (data[find] == ','):
|
||||||
try:
|
try:
|
||||||
assert not done
|
assert not done
|
||||||
assert int(data[find+1])
|
assert int(data[find + 1])
|
||||||
data = data[0:find] + data[find+1:]
|
data = data[0:find] + data[find + 1:]
|
||||||
data = data[0:find] + data[find+1:]
|
data = data[0:find] + data[find + 1:]
|
||||||
except:
|
except BaseException:
|
||||||
done = True
|
done = True
|
||||||
try:
|
try:
|
||||||
assert not done
|
assert not done
|
||||||
while True:
|
while True:
|
||||||
assert int(data[find])
|
assert int(data[find])
|
||||||
data = data[0:find] + data[find+1:]
|
data = data[0:find] + data[find + 1:]
|
||||||
except: pass
|
except BaseException:
|
||||||
|
pass
|
||||||
|
|
||||||
find = data.find('\x03')
|
find = data.find('\x03')
|
||||||
|
|
||||||
data = data.replace('\x02','')
|
data = data.replace('\x02', '')
|
||||||
data = data.replace('\x1d','')
|
data = data.replace('\x1d', '')
|
||||||
data = data.replace('\x1f','')
|
data = data.replace('\x1f', '')
|
||||||
data = data.replace('\x16','')
|
data = data.replace('\x16', '')
|
||||||
data = data.replace('\x0f','')
|
data = data.replace('\x0f', '')
|
||||||
return data
|
return data
|
||||||
|
|
||||||
|
|
||||||
class DatabaseThread:
|
class DatabaseThread:
|
||||||
@staticmethod
|
@staticmethod
|
||||||
def worker_safe(db, log_queue, internal_log, debug_log_saves=False, batch_size=50) -> None:
|
def worker_safe(
|
||||||
|
db,
|
||||||
|
log_queue,
|
||||||
|
internal_log,
|
||||||
|
debug_log_saves=False,
|
||||||
|
batch_size=50) -> None:
|
||||||
while True:
|
while True:
|
||||||
try:
|
try:
|
||||||
DatabaseThread.worker(db, log_queue, internal_log, debug_log_saves, batch_size)
|
DatabaseThread.worker(
|
||||||
|
db, log_queue, internal_log, debug_log_saves, batch_size)
|
||||||
break
|
break
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
with internal_log.error() as target:
|
with internal_log.error() as target:
|
||||||
target.write('Worker thread crashed: {0} {1}\n'.format(type(e), str(e)))
|
target.write(
|
||||||
|
'Worker thread crashed: {0} {1}\n'.format(
|
||||||
|
type(e), str(e)))
|
||||||
target.write('Stack trace: ' + traceback.format_exc())
|
target.write('Stack trace: ' + traceback.format_exc())
|
||||||
target.write('Restarting worker thread in 5 seconds...\n\n')
|
target.write(
|
||||||
|
'Restarting worker thread in 5 seconds...\n\n')
|
||||||
sleep(5)
|
sleep(5)
|
||||||
continue
|
continue
|
||||||
|
|
||||||
@staticmethod
|
@staticmethod
|
||||||
def worker(db, log_queue, internal_log, debug_log_saves=False, batch_size=50) -> None:
|
def worker(
|
||||||
|
db,
|
||||||
|
log_queue,
|
||||||
|
internal_log,
|
||||||
|
debug_log_saves=False,
|
||||||
|
batch_size=50) -> None:
|
||||||
stop = False
|
stop = False
|
||||||
while not stop:
|
while not stop:
|
||||||
first = log_queue.get()
|
first = log_queue.get()
|
||||||
@@ -549,29 +825,42 @@ class DatabaseThread:
|
|||||||
items.append(nxt)
|
items.append(nxt)
|
||||||
|
|
||||||
try:
|
try:
|
||||||
DatabaseThread.save_batch(db, items, log_queue, internal_log, debug_log_saves)
|
DatabaseThread.save_batch(
|
||||||
|
db, items, log_queue, internal_log, debug_log_saves)
|
||||||
finally:
|
finally:
|
||||||
# exactly one task_done() per get(), after the batch is finished
|
# exactly one task_done() per get(), after the batch is
|
||||||
|
# finished
|
||||||
for _ in range(taken):
|
for _ in range(taken):
|
||||||
log_queue.task_done()
|
log_queue.task_done()
|
||||||
|
|
||||||
@staticmethod
|
@staticmethod
|
||||||
def save_batch(db, items, log_queue, internal_log, debug_log_saves) -> None:
|
def save_batch(
|
||||||
|
db,
|
||||||
|
items,
|
||||||
|
log_queue,
|
||||||
|
internal_log,
|
||||||
|
debug_log_saves) -> None:
|
||||||
while True:
|
while True:
|
||||||
try:
|
try:
|
||||||
db.ensure_connected(internal_log, str(items[0]['_id']))
|
db.ensure_connected(internal_log, str(items[0]['_id']))
|
||||||
db.insert_batch(items)
|
db.insert_batch(items)
|
||||||
if debug_log_saves:
|
if debug_log_saves:
|
||||||
with internal_log.debug() as target:
|
with internal_log.debug() as target:
|
||||||
target.write('Saved {} log items queue_size={}\n'.format(len(items), log_queue.qsize()))
|
target.write(
|
||||||
|
'Saved {} log items queue_size={}\n'.format(
|
||||||
|
len(items), log_queue.qsize()))
|
||||||
return
|
return
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
sleep_for = 10
|
sleep_for = 10
|
||||||
|
|
||||||
with internal_log.error() as target:
|
with internal_log.error() as target:
|
||||||
target.write('Could not save to database caused by: {0} {1}\n'.format(type(e), str(e)))
|
target.write(
|
||||||
|
'Could not save to database caused by: {0} {1}\n'.format(
|
||||||
|
type(e), str(e)))
|
||||||
target.write('Stack trace: ' + traceback.format_exc())
|
target.write('Stack trace: ' + traceback.format_exc())
|
||||||
target.write('Batch of {} rows, first log: '.format(len(items)))
|
target.write(
|
||||||
|
'Batch of {} rows, first log: '.format(
|
||||||
|
len(items)))
|
||||||
item_copy = items[0].copy()
|
item_copy = items[0].copy()
|
||||||
item_copy['_id'] = str(item_copy['_id'])
|
item_copy['_id'] = str(item_copy['_id'])
|
||||||
json.dump(item_copy, target)
|
json.dump(item_copy, target)
|
||||||
@@ -580,27 +869,35 @@ class DatabaseThread:
|
|||||||
|
|
||||||
sleep(sleep_for)
|
sleep(sleep_for)
|
||||||
|
|
||||||
|
|
||||||
class InternalLog:
|
class InternalLog:
|
||||||
def __init__(self, save_path: str):
|
def __init__(self, save_path: str):
|
||||||
self.save_path = save_path
|
self.save_path = save_path
|
||||||
|
self.debug_enabled = False
|
||||||
|
|
||||||
def debug(self):
|
def debug(self):
|
||||||
|
if not self.debug_enabled:
|
||||||
|
from io import StringIO
|
||||||
|
return StringIO()
|
||||||
return self.open('debug')
|
return self.open('debug')
|
||||||
|
|
||||||
def error(self):
|
def error(self):
|
||||||
return self.open('error')
|
return self.open('error')
|
||||||
|
|
||||||
|
def set_debug_enabled(self, enabled: bool):
|
||||||
|
self.debug_enabled = enabled
|
||||||
|
|
||||||
def open(self, level: str):
|
def open(self, level: str):
|
||||||
target = open(os.path.join(self.save_path, level + '.log'), 'a')
|
target = open(os.path.join(self.save_path, level + '.log'), 'a')
|
||||||
return target
|
return target
|
||||||
|
|
||||||
|
|
||||||
|
|
||||||
class Database:
|
class Database:
|
||||||
def __init__(self, dsn: dict):
|
def __init__(self, dsn: dict):
|
||||||
self.dsn = dsn
|
self.dsn = dsn
|
||||||
self.conn = None
|
self.conn = None
|
||||||
|
|
||||||
|
|
||||||
class MSSQLDatabase(Database):
|
class MSSQLDatabase(Database):
|
||||||
def connect(self) -> None:
|
def connect(self) -> None:
|
||||||
import pymssql
|
import pymssql
|
||||||
@@ -617,7 +914,18 @@ class MSSQLDatabase(Database):
|
|||||||
the transaction is rolled back and the connection is dropped."""
|
the transaction is rolled back and the connection is dropped."""
|
||||||
try:
|
try:
|
||||||
for row in rows:
|
for row in rows:
|
||||||
params = (row['znc_user'], row['date'], row['code'], row['network'], row['channel'], row['host'], row['user'], row['ident'], row['user_mode'], row['target_user'], row['message'])
|
params = (
|
||||||
|
row['znc_user'],
|
||||||
|
row['date'],
|
||||||
|
row['code'],
|
||||||
|
row['network'],
|
||||||
|
row['channel'],
|
||||||
|
row['host'],
|
||||||
|
row['user'],
|
||||||
|
row['ident'],
|
||||||
|
row['user_mode'],
|
||||||
|
row['target_user'],
|
||||||
|
row['message'])
|
||||||
cur = self.conn.cursor()
|
cur = self.conn.cursor()
|
||||||
try:
|
try:
|
||||||
cur.callproc("add_log", params)
|
cur.callproc("add_log", params)
|
||||||
|
|||||||
Reference in New Issue
Block a user