Using logging throughout the bot now

.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
 

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."""

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

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)
 

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:

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)

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))

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):

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 *

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: