From d08c56f59482d17fe5a32a7b2ee69ee15461cfef Mon Sep 17 00:00:00 2001 From: Ben Kurtovic Date: Sat, 5 Nov 2011 00:53:21 -0400 Subject: [PATCH] Using logging throughout the bot now --- .gitignore | 6 +++--- bot/classes/connection.py | 5 +++-- bot/commands/__init__.py | 17 ++++++++-------- bot/config.py | 2 +- bot/frontend.py | 8 +++++--- bot/main.py | 52 ++++++++++++++++++++++++++--------------------- bot/tasks/__init__.py | 25 ++++++++++++----------- bot/watcher.py | 5 ++++- bot/wiki/__init__.py | 4 ++++ bot/wiki/site.py | 5 +++-- 10 files changed, 74 insertions(+), 55 deletions(-) diff --git a/.gitignore b/.gitignore index 42c98e0..edef0ae 100644 --- a/.gitignore +++ b/.gitignore @@ -4,12 +4,12 @@ # Ignore bot-specific config file: config.json +# Ignore logs directory: +logs/ + # Ignore cookies file: .cookies -# Ignore statistics file: -statistics.txt - # Ignore OS X's crud: .DS_Store diff --git a/bot/classes/connection.py b/bot/classes/connection.py index 8e2774a..0b6ca1f 100644 --- a/bot/classes/connection.py +++ b/bot/classes/connection.py @@ -12,12 +12,13 @@ class Connection(object): """A class to interface with IRC.""" def __init__(self, host=None, port=None, nick=None, ident=None, - realname=None): + realname=None, logger=None): self.host = host self.port = port self.nick = nick self.ident = ident self.realname = realname + self.logger = logger # A lock to prevent us from sending two messages at once: self.lock = threading.Lock() @@ -50,7 +51,7 @@ class Connection(object): # Ensure that we only send one message at a time with a blocking lock: with self.lock: self.sock.sendall(msg + "\r\n") - print " %s" % msg + self.logger.debug(msg) def say(self, target, msg): """Send a private message to a target on the server.""" diff --git a/bot/commands/__init__.py b/bot/commands/__init__.py index aad4936..a17c32c 100644 --- a/bot/commands/__init__.py +++ b/bot/commands/__init__.py @@ -7,9 +7,9 @@ This package provides the IRC "commands" used by the bot's front-end component. In __init__, you can find some functions used to load and run these commands. """ +import logging import os import sys -import traceback from classes import BaseCommand import config @@ -23,6 +23,9 @@ base_dir = os.path.join(config.root_dir, "bot", "commands") # is an instance of the command's class: _commands = {} +# Logger for this module: +logger = logging.getLogger("tasks") + def _load_command(connection, filename): """Try to load a specific command from a module, identified by file name. @@ -39,8 +42,7 @@ def _load_command(connection, filename): try: __import__(name) except: - print "Couldn't load file {0}:".format(filename) - traceback.print_exc() + logger.exception("Couldn't load file {0}".format(filename)) return command = sys.modules[name].Command(connection) @@ -48,7 +50,7 @@ def _load_command(connection, filename): return _commands[command.name] = command - print "Added command {0}...".format(command.name) + logger.debug("Added command {0}".format(command.name)) def load(connection): """Load all valid commands into the _commands global variable. @@ -67,8 +69,8 @@ def load(connection): except AttributeError: pass # The file is doesn't contain a command, so just move on - msg = "Found {0} commands: {1}." - print msg.format(len(_commands), ", ".join(_commands.keys())) + msg = "Found {0} commands: {1}" + logger.info(msg.format(len(_commands), ", ".join(_commands.keys()))) def get_all(): """Return our dict of all loaded commands.""" @@ -85,6 +87,5 @@ def check(hook, data): try: command.process(data) except: - print "Error executing command '{0}':".format(data.command) - traceback.print_exc() + logger.exception("Error executing command '{0}'".format(data.command)) break diff --git a/bot/config.py b/bot/config.py index 813c613..8c78c0b 100644 --- a/bot/config.py +++ b/bot/config.py @@ -70,7 +70,7 @@ def _setup_logging(): stream_handler = logging.StreamHandler() main_handler.setLevel(logging.INFO) - error_handler.setLevel(logging.ERROR) + error_handler.setLevel(logging.WARNING) debug_handler.setLevel(logging.DEBUG) stream_handler.setLevel(logging.DEBUG) diff --git a/bot/frontend.py b/bot/frontend.py index a043f1b..1e98d50 100644 --- a/bot/frontend.py +++ b/bot/frontend.py @@ -9,6 +9,7 @@ of BaseCommand in irc/base_command.py. All command classes are automatically imported by irc/command_handler.py if they are in irc/commands. """ +import logging import re import config @@ -18,6 +19,7 @@ from classes import Connection, Data, BrokenSocketException __all__ = ["get_connection", "startup", "main"] connection = None +logger = logging.getLogger("frontend") sender_regex = re.compile(":(.*?)!(.*?)@(.*?)\Z") def get_connection(): @@ -25,7 +27,7 @@ def get_connection(): connection, but don't actually connect yet.""" cf = config.irc["frontend"] connection = Connection(cf["host"], cf["port"], cf["nick"], cf["ident"], - cf["realname"]) + cf["realname"], logger) return connection def startup(conn): @@ -48,7 +50,7 @@ def main(): try: read_buffer = read_buffer + connection.get() except BrokenSocketException: - print "Socket has broken on front-end; restarting bot..." + logger.warn("Socket has broken on front-end; restarting bot") return lines = read_buffer.split("\n") @@ -90,7 +92,7 @@ def _process_message(line): # ordinary command): if data.msg in ["!restart", ".restart"]: if data.host in config.irc["permissions"]["owners"]: - print "Restarting bot per owner request..." + logger.info("Restarting bot per owner request") return True # If we are pinged, pong back: diff --git a/bot/main.py b/bot/main.py index 0e51d67..a400e77 100644 --- a/bot/main.py +++ b/bot/main.py @@ -30,9 +30,9 @@ There is a "priority" system here: Else, the bot will stop, as no components are enabled. """ +import logging import threading import time -import traceback import config import frontend @@ -49,13 +49,12 @@ def irc_watcher(f_conn=None): while 1: # restart the watcher component if it breaks (and nothing else) w_conn = watcher.get_connection() w_conn.connect() - print # blank line to signify that the bot has finished starting up try: watcher.main(w_conn, f_conn) except: - traceback.print_exc() + logging.exception("Watcher had an error") time.sleep(5) # sleep a bit before restarting watcher - print "\nWatcher has stopped; restarting component..." + logging.warn("Watcher has stopped; restarting component") def wiki_scheduler(): """Function to handle the wiki scheduler as another thread, or as the @@ -77,12 +76,12 @@ def irc_frontend(): enabled.""" global f_conn - print "Starting IRC frontend..." + logging.info("Starting IRC frontend") f_conn = frontend.get_connection() frontend.startup(f_conn) if "wiki_schedule" in config.components: - print "\nStarting wiki scheduler..." + logging.info("Starting wiki scheduler") tasks.load() t_scheduler = threading.Thread(target=wiki_scheduler) t_scheduler.name = "wiki-scheduler" @@ -90,7 +89,7 @@ def irc_frontend(): t_scheduler.start() if "irc_watcher" in config.components: - print "\nStarting IRC watcher..." + logging.info("Starting IRC watcher") t_watcher = threading.Thread(target=irc_watcher, args=(f_conn,)) t_watcher.name = "irc-watcher" t_watcher.daemon = True @@ -105,40 +104,47 @@ def irc_frontend(): def run(): config.load() try: - key = raw_input() # wait for our password decrypt key from the bot's - except EOFError: # wrapper, then decrypt passwords + # Wait for our password decrypt key from the bot's wrapper, then + # decrypt passwords: + key = raw_input() + except EOFError: pass else: config.decrypt(key) enabled = config.components - if "irc_frontend" in enabled: # make the frontend run on our primary - irc_frontend() # thread if enabled, and enable additional - # components through that function + if "irc_frontend" in enabled: + # Make the frontend run on our primary thread if enabled, and enable + # additional components through that function + irc_frontend() - elif "wiki_schedule" in enabled: # run the scheduler on the main - print "Starting wiki scheduler..." # thread, but also run the IRC - tasks.load() # watcher on another thread iff it - if "irc_watcher" in enabled: # is enabled - print "\nStarting IRC watcher..." + elif "wiki_schedule" in enabled: + # Run the scheduler on the main thread, but also run the IRC watcher on + # another thread iff it is enabled + logging.info("Starting wiki scheduler") + tasks.load() + if "irc_watcher" in enabled: + logging.info("Starting IRC watcher") t_watcher = threading.Thread(target=irc_watcher) t_watcher.name = "irc-watcher" t_watcher.daemon = True t_watcher.start() wiki_scheduler() - elif "irc_watcher" in enabled: # the IRC watcher is our only enabled - print "Starting IRC watcher..." # component, so run its function only - irc_watcher() # and don't worry about anything else + elif "irc_watcher" in enabled: + # The IRC watcher is our only enabled component, so run its function + # only and don't worry about anything else: + logging.info("Starting IRC watcher") + irc_watcher() - else: # nothing is enabled! - print "No bot parts are enabled; stopping..." + else: # Nothing is enabled! + logging.critical("No bot parts are enabled; stopping") exit(1) if __name__ == "__main__": try: run() except KeyboardInterrupt: - print "\nKeyboardInterrupt: stopping main bot loop." + logging.critical("KeyboardInterrupt: stopping main bot loop") exit(1) diff --git a/bot/tasks/__init__.py b/bot/tasks/__init__.py index 402f46a..f1a8b17 100644 --- a/bot/tasks/__init__.py +++ b/bot/tasks/__init__.py @@ -7,11 +7,11 @@ This package provides the wiki bot "tasks" EarwigBot runs. Here in __init__, you can find some functions used to load and run these tasks. """ +import logging import os import sys import threading import time -import traceback from classes import BaseTask import config @@ -25,6 +25,9 @@ base_dir = os.path.join(config.root_dir, "bot", "tasks") # an instance of the task class: _tasks = {} +# Logger for this module: +logger = logging.getLogger("commands") + def _load_task(filename): """Try to load a specific task from a module, identified by file name.""" global _tasks @@ -34,8 +37,7 @@ def _load_task(filename): try: __import__(name) except: - print "Couldn't load file {0}:".format(filename) - traceback.print_exc() + logger.exception("Couldn't load file {0}:".format(filename)) return task = sys.modules[name].Task() @@ -44,18 +46,17 @@ def _load_task(filename): return _tasks[task.name] = task - print "Added task {0}...".format(task.name) + logger.debug("Added task {0}".format(task.name)) def _wrapper(task, **kwargs): """Wrapper for task classes: run the task and catch any errors.""" try: task.run(**kwargs) except: - error = "Task '{0}' raised an exception and had to stop:" - print error.format(task.name) - traceback.print_exc() + error = "Task '{0}' raised an exception and had to stop" + logger.exception(error.format(task.name)) else: - print "Task '{0}' finished without error.".format(task.name) + logger.info("Task '{0}' finished without error".format(task.name)) def load(): """Load all valid tasks from bot/tasks/, into the _tasks variable.""" @@ -70,7 +71,7 @@ def load(): except AttributeError: pass # The file is doesn't contain a task, so just move on - print "Found {0} tasks: {1}.".format(len(_tasks), ', '.join(_tasks.keys())) + logger.info("Found {0} tasks: {1}".format(len(_tasks), ', '.join(_tasks.keys()))) def schedule(now=time.gmtime()): """Start all tasks that are supposed to be run at a given time.""" @@ -87,13 +88,13 @@ def schedule(now=time.gmtime()): def start(task_name, **kwargs): """Start a given task in a new thread. Pass args to the task's run() function.""" - print "Starting task '{0}' in a new thread...".format(task_name) + logger.info("Starting task '{0}' in a new thread".format(task_name)) try: task = _tasks[task_name] except KeyError: - error = "Couldn't find task '{0}': bot/tasks/{0}.py does not exist." - print error.format(task_name) + error = "Couldn't find task '{0}': bot/tasks/{0}.py does not exist" + logger.error(error.format(task_name)) return task_thread = threading.Thread(target=lambda: _wrapper(task, **kwargs)) diff --git a/bot/watcher.py b/bot/watcher.py index 551e7df..577cc6e 100644 --- a/bot/watcher.py +++ b/bot/watcher.py @@ -10,11 +10,14 @@ being started (located in tasks/) or messages being sent to channels on the IRC frontend. """ +import logging + import config from classes import Connection, RC, BrokenSocketException import rules frontend_conn = None +logger = logging.getLogger("watcher") def get_connection(): """Return a new Connection() instance with connection information. @@ -23,7 +26,7 @@ def get_connection(): """ cf = config.irc["watcher"] connection = Connection(cf["host"], cf["port"], cf["nick"], cf["ident"], - cf["realname"]) + cf["realname"], logger) return connection def main(connection, f_conn=None): diff --git a/bot/wiki/__init__.py b/bot/wiki/__init__.py index dd9bde9..f795d77 100644 --- a/bot/wiki/__init__.py +++ b/bot/wiki/__init__.py @@ -10,6 +10,10 @@ written by Mr.Z-man, other than a similar purpose. We share no code. Import the toolset with `import wiki`. """ +import logging +logger = logging.getLogger("wiki") +logger.addHandler(logging.NullHandler()) + from wiki.constants import * from wiki.exceptions import * from wiki.functions import * diff --git a/bot/wiki/site.py b/bot/wiki/site.py index 6e415a0..624a86c 100644 --- a/bot/wiki/site.py +++ b/bot/wiki/site.py @@ -16,6 +16,7 @@ try: except ImportError: oursql = None +from wiki import logger from wiki.category import Category from wiki.constants import * from wiki.exceptions import * @@ -169,7 +170,7 @@ class Site(object): data = urlencode(params) - print url, data # debug code + logger.debug("{0} -> {1}".format(url, data)) try: response = self._opener.open(url, data) @@ -207,7 +208,7 @@ class Site(object): raise SiteAPIError(e.format(self._max_retries)) tries += 1 msg = 'Server says: "{0}". Retrying in {1} seconds ({2}/{3}).' - print msg.format(info, wait, tries, self._max_retries) + logger.info(msg.format(info, wait, tries, self._max_retries)) sleep(wait) return self._api_query(params, tries=tries, wait=wait*3) else: