elia/boots
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity

This change introduces better logging for the bot

Browse source 
You can configure the logging system by configuring config/logging.yaml
This commit is contained in:
Elijah Lazkani 2017-09-16 12:05:41 -04:00
parent 51312c9e28
commit 2072e53144
10 changed files with 135 additions and 64 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

1
README.md
View file

@ -9,6 +9,7 @@ If you are reading this then you are welcome to contribute code, reviews are a p
This code only requires the following dependencies:
* [bottom](https://github.com/numberoverzero/bottom)
* [aiofiles](https://github.com/Tinche/aiofiles)
* [pyyaml](https://github.com/yaml/pyyaml)
## 8ball

84
boots/admin.py
View file

@ -21,7 +21,7 @@ class Admin:
LIST = re.compile(r'^list.*$')
def __init__(self, client: robot.Bot, config: str = None):
self.logger = logging.getLogger("boots.admin.Admin")
self.logger = logging.getLogger(__class__.__name__)
self.logger.debug("Initializing...")
self.client = client
self.config = config or "./config/admin.pkl"
@ -36,7 +36,7 @@ class Admin:
:return: None
"""
self.logger.debug("init() Loading config")
self.logger.debug("We are loading the configuration")
await self.load_config()
@staticmethod
@ -112,19 +112,20 @@ class Admin:
:param config str: the path to the configuration
:return: None
"""
self.logger.debug("load_config() attempting to load configuration {}".format(config))
self.logger.info("Loading configuration...")
self.logger.debug("Attempting to load configuration {}".format(config))
try:
async with aiofiles.open(self.abspath(config or self.config), mode='rb') as f:
_file = await f.read()
try:
self.admins = pickle.loads(_file)
except pickle.PickleError:
self.logger.warn("load_config() failed to load configuration, creating a new one")
self.logger.warn("We failed to load configuration, creating a new one")
self.admins = {}
await self.add_admin("Admin", "Pa$$w0rd", 1000)
f.close()
except FileNotFoundError:
self.logger.warn("load_config() failed to read the configuration file, creating a new configuration")
self.logger.warn("We failed to read the configuration file, creating a new configuration")
self.admins = {}
await self.add_admin("Admin", "Pa$$w0rd", 1000)
@ -135,7 +136,7 @@ class Admin:
:param config str: the path to the configuration
:return: None
"""
self.logger.debug("Attempting to write to drive...")
self.logger.debug("We are attempting to write to drive...")
async with aiofiles.open(self.abspath(config or self.config), mode='wb+') as f:
_file = pickle.dumps(self.admins)
await f.write(_file)
@ -151,7 +152,7 @@ class Admin:
:param password str: the password to be added
:return: None
"""
self.logger.debug("add_admin() adding {}".format(user))
self.logger.debug("Adding {}".format(user))
self.admins[user] = {}
self.admins[user]['password'] = self.hash(password)
self.admins[user]['level'] = level
@ -160,7 +161,7 @@ class Admin:
self.admins[user]['logged_in_nick'] = None
self.admins[user]['LOGIN'] = re.compile(
r'^login\s+({})\s+({})\s*$'.format(user, re.escape(self.hash(password))))
self.logger.debug("add_admin() calling save_config()")
self.logger.debug("We are calling save_config()")
await self.save_config()
async def rm_admin(self, user: str) -> None:
@ -173,9 +174,9 @@ class Admin:
:param user str: the key user to delete from the list of admins
:return: None
"""
self.logger.debug("rm_admin() removing {}".format(user))
self.logger.debug("We are removing {}".format(user))
del self.admins[user]
self.logger.debug("rm_admin() calling save_config()")
self.logger.debug("We are calling save_config()")
await self.save_config()
async def _handle(self, nick: str, target: str, message: str, **kwargs: dict) -> None:
@ -189,12 +190,12 @@ class Admin:
:param kwargs dict: for API compatibility
:return: None
"""
self.logger.debug("_handle() nick={} target={} message={} kwargs={}".format(
self.logger.debug("We have received nick={} target={} message={} kwargs={}".format(
nick, target, message, kwargs))
# Set the admin flag
admin = self.is_admin(nick, kwargs['host'])
self.logger.debug("_handle() check if {} is admin".format(nick))
self.logger.debug("We are checking to see if {} is an admin".format(nick))
if admin:
kwargs['is_admin'] = True
kwargs['level'] = self.admins[admin]['level']
@ -203,7 +204,7 @@ class Admin:
if kwargs.get('level', None) is not None:
del kwargs['level']
self.logger.debug("_handle() is parsing the message sent by {}".format(nick))
self.logger.debug("We are parsing the message sent by {}".format(nick))
if self.HELP.match(message):
self.admin_help(nick, target, message, **kwargs)
elif self.LOGIN.match(message):
@ -219,11 +220,11 @@ class Admin:
elif self.LIST.match(message):
self.admin_list(nick, target, **kwargs)
self.logger.debug("_handle() is modifying kwargs")
self.logger.debug("We are modifying kwargs")
kwargs['nick'] = nick
kwargs['target'] = target
kwargs['message'] = message
self.logger.debug("_handle() is trigger a new event called ADMIN with {}".format(kwargs))
self.logger.debug("We are triggering a new event called ADMIN with {}".format(kwargs))
self.client.trigger('ADMIN', **kwargs)
def admin_help(self, nick: str, target: str, message: str, **kwargs: dict) -> None:
@ -247,7 +248,7 @@ class Admin:
:return: None
"""
if target == self.client.nick:
self.logger.debug("admin_help() received a help request from {}".format(nick))
self.logger.debug("We have received a help request from {}".format(nick))
if kwargs.get("is_admin", None) is True:
match_help = self.HELP.match(message)
match_help_cmd = self.HELP_CMD.match(message)
@ -264,7 +265,9 @@ class Admin:
kwargs['message'] = "passwd <new password> - Change your account\'s password"
self.client.send("PRIVMSG", **kwargs)
if match_help_cmd.group(1) == 'add':
kwargs['message'] = "add <user> <password> - adds an admin account to the list of admins"
kwargs['message'] = \
"add <user> <password> <level> - adds an admin account to the list of" \
"admins with provided level"
self.client.send("PRIVMSG", **kwargs)
if match_help_cmd.group(1) == 'rm':
kwargs['message'] = "rm <user> - removes an admin from the list of admins"
@ -296,7 +299,7 @@ class Admin:
:return: None
"""
if target == self.client.nick:
self.logger.debug("log_in() is called by {}".format(nick))
self.logger.debug("We are being called by {}".format(nick))
match = self.LOGIN.match(message)
user = self.admins.get(match.group(1), None)
if user:
@ -305,12 +308,12 @@ class Admin:
if kwargs.get('is_admin', None) is True and \
match.group(1) != self.is_admin(nick, kwargs['host']):
self.logger.warn(
"log_in() {} already logged in as different user, logging him out".format(nick))
"We detected that {} is already logged in as different user, logging him out".format(nick))
await self.log_out(nick, target, **kwargs)
if match.group(1) == self.is_admin(nick, kwargs['host']):
kwargs['target'] = nick
kwargs['message'] = "{} you are already logged in...".format(nick)
self.logger.warn("log_in() {} already logged in, notifying".format(nick))
self.logger.warn("We detected that {} is already logged in, notifying".format(nick))
else:
self.admins[match.group(1)]['logged_in'] = True
self.admins[match.group(1)]['logged_in_nick'] = str(nick)
@ -319,10 +322,9 @@ class Admin:
kwargs['target'] = nick
kwargs['message'] = "{}, you are logged in to {} successfully".format(
nick, match.group(1))
self.logger.debug("log_in() {} has been logged in successfully, notifying".format(nick))
self.logger.debug("LOGIN from kwargs: {}".format(kwargs))
self.logger.debug("We have logged in {} successfully, notifying".format(nick))
self.client.send("PRIVMSG", **kwargs)
self.logger.debug("log_in() is calling save_config()")
self.logger.debug("We are calling save_config()")
await self.save_config()
async def log_out(self, nick: str, target: str, **kwargs: dict) -> None:
@ -341,7 +343,7 @@ class Admin:
:return: None
"""
if target == self.client.nick:
self.logger.debug("log_out() is being called by {}".format(nick))
self.logger.debug("We are being called by {}".format(nick))
if kwargs.get('is_admin', None) is True:
admin = self.is_admin(nick, kwargs['host'])
if admin:
@ -352,9 +354,9 @@ class Admin:
kwargs['target'] = nick
kwargs['message'] = "{}, you are logged out of {} successfully".format(
nick, admin)
self.logger.debug("log_out() {} has been successfully logged out, notifying".format(nick))
self.logger.debug("We have successfully logged {} out, notifying".format(nick))
self.client.send("PRIVMSG", **kwargs)
self.logger.debug("log_out() is calling save_config")
self.logger.debug("We are calling save_config")
await self.save_config()
async def passwd(self, nick: str, target: str, message: str, **kwargs: dict) -> None:
@ -371,7 +373,7 @@ class Admin:
:return: None
"""
if target == self.client.nick:
self.logger.debug("passwd() is being called by {}".format(nick))
self.logger.debug("We are being called by {}".format(nick))
if kwargs.get('is_admin', None) is True:
match = self.PASSWD.match(message)
if len(match.groups()) == 1:
@ -382,12 +384,12 @@ class Admin:
kwargs['target'] = nick
kwargs['message'] = '{}, password for {} has been successfully changed...'.format(
nick, admin)
self.logger.debug("passwd() password for {} has been successfully changed, notifying".format(nick))
self.logger.debug("We have successfully changed {}'s password, notifying".format(nick))
self.client.send("PRIVMSG", **kwargs)
self.logger.debug("passwd() is calling save_config()")
self.logger.debug("We are calling save_config()")
await self.save_config()
kwargs['target'] = self.client.nick
self.logger.debug("passwd() is logging {} out".format(nick))
self.logger.debug("We are logging {} out".format(nick))
await self.log_out(nick, **kwargs)
async def admin_add(self, nick: str, target: str, message: str, **kwargs: dict) -> None:
@ -404,7 +406,7 @@ class Admin:
:return: None
"""
if target == self.client.nick:
self.logger.debug("admin_add() is called by {}".format(nick))
self.logger.debug("We are being called by {}".format(nick))
if kwargs.get('is_admin', None) is True:
match = self.ADD.match(message)
if len(match.groups()) == 3:
@ -414,14 +416,14 @@ class Admin:
kwargs['message'] = "{} has been added with level {}...".format(
match.group(1), level)
self.logger.debug(
"admin_add() admin {} has been added with level {}, notifying {}".format(
"We have added {} with level {}, notifying {}".format(
match.group(1), level, nick))
await self.add_admin(match.group(1), match.group(2), level)
else:
kwargs['target'] = nick
kwargs['message'] = "{} has already been added...".format(match.group(1))
self.logger.warn(
"admin_add() {} has already been added, notifying {}".format(match.group(1), nick))
"We detected that {} has already been added, notifying {}".format(match.group(1), nick))
self.client.send("PRIVMSG", **kwargs)
async def admin_rm(self, nick: str, target: str, message: str, **kwags: dict) -> None:
@ -440,7 +442,7 @@ class Admin:
:return: None
"""
if target == self.client.nick:
self.logger.debug("admin_rm() is being called by {}".format(nick))
self.logger.debug("We are being called by {}".format(nick))
if kwags.get('is_admin', None) is True:
match = self.RM.match(message)
if len(match.groups()) == 1:
@ -454,7 +456,7 @@ class Admin:
kwags['level'] == self.admins[match.group(1)]['level']):
kwags['target'] = nick
kwags['message'] = "{} has been removed...".format(match.group(1))
self.logger.debug("admin_rm() admin {} has been removed, notifying {}".format(
self.logger.debug("We removed {} successfully, notifying {}".format(
match.group(1), nick))
await self.rm_admin(match.group(1))
else:
@ -462,7 +464,7 @@ class Admin:
kwags['message'] = "{}, you do not have enough access to delete {}".format(
nick, match.group(1))
self.logger.warn(
"admin_rm() {0} does not have enough access to delete {1}, notifying {0}".format(
"We detected that {0} does not have enough access to delete {1}, notifying {0}".format(
nick, match.group(1)))
self.client.send("PRIVMSG", **kwags)
@ -476,7 +478,7 @@ class Admin:
:return: None
"""
if target == self.client.nick:
self.logger.debug("admin_list() is being called by {}".format(nick))
self.logger.debug("We are being called by {}".format(nick))
if kwargs.get('is_admin', None) is True:
admins = ""
for key, _ in self.admins.items():
@ -488,7 +490,7 @@ class Admin:
kwargs['message'] = "List of Administrators:"
self.client.send("PRIVMSG", **kwargs)
kwargs['message'] = admins
self.logger.debug("admin_list() is returning admin list page to user {}".format(
self.logger.debug("We are returning admin list page to {}".format(
kwargs))
self.client.send("PRIVMSG", **kwargs)
@ -501,12 +503,12 @@ class Admin:
:param host str: the host to check against
:return str: account if admin in list of admins
"""
self.logger.debug("is_admin() is being called for {}".format(user))
self.logger.debug("We are being called for {}".format(user))
for admin, value in self.admins.items():
if value.get('logged_in', None) and \
value.get('logged_in_nick', None) == user and \
value.get('logged_in_hostname', None) == host:
self.logger.debug("is_admin() is returning {} as an admin".format(user))
self.logger.debug("We are returning {} as an admin".format(user))
return admin
self.logger.debug("is_admin() is returning nothing, {} is not an admin".format(user))
self.logger.debug("We are returning nothing, {} is not an admin".format(user))
return None

6
boots/admin_commands.py
View file

@ -11,7 +11,7 @@ class AdminCmd:
into known actions defined by users
"""
def __init__(self, admin: admin.Admin, modifier: str = "!"):
self.logger = logging.getLogger("boots.admin_commands.AdminCmd")
self.logger = logging.getLogger(__class__.__name__)
self.logger.debug("Initializing...")
self.admin = admin
self.client = admin.client
@ -30,11 +30,11 @@ class AdminCmd:
:return: None
"""
if bool(kwargs.get('is_admin', None)):
self.logger.debug("_handle() is being called by {}".format(kwargs['nick']))
self.logger.debug("We are being called by {}".format(kwargs['nick']))
for regex, (func, pattern) in self.services.items():
match = regex.match(message)
if match:
self.logger.debug("_handle() calling the function that matched the regex {}".format(regex))
self.logger.debug("We are calling the function that matched the regex {}".format(regex))
split_msg = message.split(" ")
message = " ".join(split_msg[1:])
self.client.loop.create_task(

6
boots/boots.py
View file

@ -4,10 +4,10 @@ import robot
import eightball
import admin
import admin_commands
from logger import setup_logging
FORMAT = '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
logging.basicConfig(level=logging.DEBUG, format=FORMAT)
logger = logging.getLogger('boots')
setup_logging("./config/logging.yaml")
logger = logging.getLogger(__name__)
async def plugins(bot: robot.Bot):

16
boots/eightball.py
View file

@ -34,7 +34,7 @@ class EightBall:
]
def __init__(self, client: robot.Bot, keyword: str = ".8ball"):
self.logger = logging.getLogger("boots.eightball.Eightball")
self.logger = logging.getLogger(__class__.__name__)
self.logger.debug("Initializing...")
self.client = client
self.questions = {}
@ -51,7 +51,7 @@ class EightBall:
:param kwargs dict:
:return: None
"""
self.logger.debug("_handle() is being called by {}".format(nick))
self.logger.debug("We are being called by {}".format(nick))
nick, target = self._prefix(nick, target)
# Check that it did not call itself
@ -64,11 +64,11 @@ class EightBall:
if is_question(match.group(1)):
answer = self._get_answer()
message = "{}, {}".format(nick, answer)
self.logger.debug("_handle() found '{}', notifying {}".format(answer, nick))
self.logger.debug("We found '{}', notifying {}".format(answer, nick))
else:
message = \
"{}, I did not detect a question for me to answer".format(nick)
self.logger.debug("_handle() did not detect a question, notifying {}".format(nick))
self.logger.debug("We did not detect a question, notifying {}".format(nick))
self.client.loop.create_task(
func(target, message, **kwargs))
@ -121,7 +121,7 @@ class EightBall:
return func
logger = logging.getLogger("boots.eightball")
logger = logging.getLogger(__name__)
def is_question(phrase: str) -> bool:
@ -131,10 +131,10 @@ def is_question(phrase: str) -> bool:
:param phrase str: the phrase to check
:return: bool if the phrase is a question or not
"""
logger.debug("is_question() is being calling aganist '{}'".format(phrase))
logger.debug("We are being called for '{}'".format(phrase))
compiled = re.compile(r'^[^\?]+\?\s*$')
if compiled.match(phrase):
logger.debug("is_question() is returning True")
logger.debug("Returning True")
return True
logger.debug("is_question() is returning False")
logger.debug("Returning False")
return False

22
boots/logger.py Normal file
View file

@ -0,0 +1,22 @@
import os
import logging.config
import yaml
def setup_logging(
default_path: str = None,
default_level: int = logging.INFO,
env_key: str = 'LOG_CFG'
):
if default_path:
path = default_path
value = os.getenv(env_key, None)
if value:
path = value
if os.path.exists(path):
with open(os.path.abspath(path), mode='r') as f:
config = yaml.safe_load(f.read())
logging.config.dictConfig(config)
else:
_format = '%(asctime)s - %(levelname)s - %(filename)s:%(name)s.%(funcName)s:%(lineno)d - %(message)s'
logging.basicConfig(level=default_level, format=_format)

17
boots/robot.py
View file

@ -17,7 +17,7 @@ class Bot(bottom.Client):
realname: str = None,
channels: list = None) -> None:
super().__init__(host=host, port=port, ssl=ssl)
self.logger = logging.getLogger("admin.robot.Bot")
self.logger = logging.getLogger(__class__.__name__)
self.logger.debug("Initializing...")
self.nick = nick
self.user = user or self.nick
@ -36,7 +36,7 @@ class Bot(bottom.Client):
:return: None
"""
message = message or ""
self.logger.debug("keepalive() PONG {}".format(message))
self.logger.debug("PONG {}".format(message))
self.send("pong", message=message)
async def on_connect(self, **kwargs: dict) -> None:
@ -47,10 +47,11 @@ class Bot(bottom.Client):
:param kwargs dict: for API compatibility
:return: None
"""
self.logger.debug("on_connect() is being called")
self.logger.debug("on_connect() is sending NICK as {} to server ".format(self.nick))
self.logger.debug("We are being called")
self.logger.info("Connecting...")
self.logger.debug("We are sending NICK as {} to server ".format(self.nick))
self.send('NICK', nick=self.nick)
self.logger.debug("on_connect() is sending USER {} {}".format(self.user, self.realname))
self.logger.debug("We are sending USER {} {}".format(self.user, self.realname))
self.send('USER', user=self.user,
realname=self.realname)
@ -64,12 +65,12 @@ class Bot(bottom.Client):
# Cancel whichever waiter's event didn't come in
for future in pending:
future.cancel()
self.logger.debug("on_connect() is auto-joining channels {}".format(self.channels))
self.logger.info("We are auto-joining channels {}".format(self.channels))
for channel in self.channels:
self.send('JOIN', channel=channel)
async def on_disconnect(self, **kwargs: dict) -> None:
self.logger.debug("on_disconnect() is being called")
self.logger.debug("We are being called")
await self.disconnect()
self.logger.debug("on_disconnect() is calling loop.stop()")
self.logger.debug("We are calling loop.stop()")
self.loop.stop()

41
config/logging.yaml Normal file
View file

@ -0,0 +1,41 @@
---
version: 1
disable_existing_loggers: False
formatters:
simple:
format: "%(asctime)s - %(levelname)s - %(filename)s:%(name)s.%(funcName)s:%(lineno)d - %(message)s"
handlers:
console:
class: logging.StreamHandler
level: DEBUG
formatter: simple
stream: ext://sys.stdout
info_file_handler:
class: logging.handlers.RotatingFileHandler
level: INFO
formatter: simple
filename: ./log/info.log
maxBytes: 10485760 # 10MB
backupCount: 20
encoding: utf8
error_file_handler:
class: logging.handlers.RotatingFileHandler
level: ERROR
formatter: simple
filename: ./log/errors.log
maxBytes: 10485760 # 10MB
backupCount: 20
encoding: utf8
loggers:
my_module:
level: ERROR
handlers: [console]
propagate: no
root:
level: DEBUG
handlers: [console, info_file_handler, error_file_handler]

3
log/README.md Normal file
View file

@ -0,0 +1,3 @@
# Log
This directory is a temporary place holder for the logs that are to be written.

3
requirements.txt
View file

@ -1,2 +1,3 @@
bottom
aiofiles
aiofiles
pyyaml