Merge pull request #23 from Bytespeicher/core/logging

Added new logging infrastructure. Closes #16

bytebot.py

@@ -16,10 +16,11 @@
 from bytebot_config             import *
 from bytebotpluginloader        import ByteBotPluginLoader
 from time                       import time
+from bytebot_log                import *
 
 from twisted.words.protocols    import irc
 from twisted.internet           import reactor, protocol, ssl, task
-from twisted.python             import log
+from twisted.python             import logfile, log
 
 class ByteBot(irc.IRCClient):
 
@@ -46,11 +47,11 @@ def connectionLost(self, reason):
         irc.IRCClient.connectionLost(self, reason)
 
     def signedOn(self):
-        print("[sign on]")
+        log.msg("[sign on]")
         self.join(self.factory.channel)
 
     def joined(self, channel):
-        print("[joined channel %s]" % channel)
+        log.msg("[joined channel %s]" % channel)
         self.factory.plugins.run('onJoined', 
                                  {
                                      'irc': self,
@@ -77,8 +78,7 @@ def privmsg(self, user, channel, msg):
         if msg.startswith(self.nickname + ":"):
             msg = "%s: Ich bin ein Bot. Meine Intelligenz ist limitiert" % user
             self.msg(channel, msg)
-            #self.logger.log("<%s> %s" % (self.nickname, msg))
-            print("<%s> %s" % (self.nickname, msg))
+            log.msg("<%s> %s" % (self.nickname, msg))
 
         if msg.startswith('!commands'):
             for pid, name in enumerate(self.plugins):
@@ -124,16 +124,16 @@ def alterCollidedNick(self, nickname):
 
     def startCron(self):
         def runPerMinute():
-            print("[running cron - every 60s]")
+            log.msg("[running cron - every 60s]")
             self.factory.plugins.run('minuteCron', {'irc': self})
 
         def runPerHour():
-            print("[running cron - every 60m]")
+            log.msg("[running cron - every 60m]")
             self.factory.plugins.run('hourCron', {'irc': self})
 
 
         def runPerDay():
-            print("[running cron - every 24h]")
+            log.msg("[running cron - every 24h]")
             self.factory.plugins.run('dayCron', {'irc': self})
 
 
@@ -163,12 +163,27 @@ def clientConnectionLost(self, connector, reason):
         connector.connect()
 
     def clientConnectionFailed(self, connector, reason):
-        print("FATAL: connection failed: ", reason)
+        log("FATAL: connection failed: %s" % reason, level=LOG_ERROR)
         reactor.stop()
 
 
 if __name__ == '__main__':
-    log.startLogging(sys.stdout)
+    # ERROR | WARNING
+    log_error = logfile.LogFile("error.log", BYTEBOT_LOGPATH,
+                                rotateLength=10000000, maxRotatedFiles=100)
+
+    # INFO | DEBUG
+    log_info  = logfile.LogFile("bytebot.log", BYTEBOT_LOGPATH,
+                                rotateLength=10000000, maxRotatedFiles=100)
+
+    logger_error = BytebotLogObserver(log_error,
+                            (BYTEBOT_LOGLEVEL & ~LOG_INFO & ~LOG_DEBUG & ~LOG_WARN))
+    logger_info  = BytebotLogObserver(log_info,
+                            (BYTEBOT_LOGLEVEL & ~LOG_ERROR))
+
+    log.addObserver(logger_error.emit)
+    log.addObserver(logger_info.emit)
+
     f = ByteBotFactory(BYTEBOT_NICK, BYTEBOT_PASSWORD, BYTEBOT_CHANNEL)
     if BYTEBOT_SSL == True:
         reactor.connectSSL(BYTEBOT_SERVER, int(BYTEBOT_PORT), f, ssl.ClientContextFactory())

bytebot_config.py.example

@@ -1,6 +1,11 @@
 #!/usr/bin/env python2
 # -*- coding: utf-8 -*-
 
+import bytebot_log
+
+BYTEBOT_LOGLEVEL    = bytebot_log.LOG_ERROR | bytebot_log.LOG_WARN
+BYTEBOT_LOGPATH     = '/var/log/bytebot/'
+
 BYTEBOT_SERVER      = ""
 BYTEBOT_PORT        = 6667
 BYTEBOT_SSL         = True
@@ -9,7 +14,6 @@ BYTEBOT_PASSWORD    = ""
 BYTEBOT_CHANNEL     = ""
 BYTEBOT_DESCRIPTION = ""
 
-BYTEBOT_DEBUG       = True
 BYTEBOT_TOPIC       = u''
 
 BYTEBOT_STATUS_URL  = 'http://status.bytespeicher.org/status.json'

bytebot_log.py

@@ -0,0 +1,25 @@
+#!/usr/bin/env python2
+# -*- coding: utf-8 -*-
+
+LOG_DEBUG = 0b0001
+LOG_INFO  = 0b0010
+LOG_WARN  = 0b0100
+LOG_ERROR = 0b1000
+
+from twisted.python import log
+
+class BytebotLogObserver(log.FileLogObserver):
+    def __init__(self, f, level=LOG_ERROR):
+        self.level = level
+        log.FileLogObserver.__init__(self, f)
+
+    def emit(self, eventDict):
+        if eventDict['isError']:
+            level = LOG_ERROR
+        elif 'level' in eventDict:
+            level = eventDict['level']
+        else:
+            level = LOG_INFO
+
+        if (self.level & level) > 0:
+            log.FileLogObserver.emit(self, eventDict)

bytebotpluginloader.py

@@ -3,6 +3,8 @@
 
 from sys                import exit
 from twisted.internet   import reactor
+from bytebot_log        import *
+from twisted.python     import log
 
 class ByteBotPluginLoader:
     """This class enables automatic loading and method calling for plugin 
@@ -27,9 +29,12 @@ def __init__(self, plugins, plugin_path='plugins'):
                     __import__("%s.%s" % (path, plugin)).__dict__[plugin],
                     plugin
                 )()
+
+                log.msg("Loaded plugin '%s'" % plugin)
             except Exception as e:
-                print("FATAL: Could not import plugin %s.%s" %
-                      (path, plugin))
+                log.msg("FATAL: Could not import plugin %s.%s" %
+                        (path, plugin),
+                        level=LOG_ERROR)
                 exit(255)
 
     def run(self, fn, args={}, threaded=True):
@@ -39,13 +44,23 @@ def run(self, fn, args={}, threaded=True):
         args            dictionary with arguments to call the method with
         threaded        if set to True, the functions will be run in a thread
         """
+        log.msg("Executing function %s on all plugins with args %s" %
+                (fn, args),
+                level=LOG_DEBUG)
         for key, plugin in self.PLUGINS.iteritems():
             try:
                 method = getattr(plugin, fn)
                 if not threaded:
+                    log.msg("Execute | non-threaded | %s->%s" %
+                            (plugin, method.__name__),
+                            level=LOG_DEBUG)
                     method(**args)
                 else:
+                    log.msg("Execute | threaded | %s->%s" %
+                            (plugin, method.__name__),
+                            level=LOG_DEBUG)
                     reactor.callInThread(method, **args)
             except Exception as e:
-                print("WARNING: An error occured while executing %s in %s with %s" %
-                     (fn, plugin, args))
+                log.msg("WARNING: An error occured while executing %s in %s with %s" %
+                        (fn, plugin, args),
+                        level=LOG_WARN)

plugins/autoop.py

@@ -3,6 +3,8 @@
 
 from plugins.plugin import Plugin
 from bytebot_config import BYTEBOT_PLUGIN_CONFIG
+from twisted.python import log
+from bytebot_log    import LOG_INFO, LOG_WARN
 
 class autoop(Plugin):
     def onIrc_JOIN(self, irc, prefix, params):
@@ -12,18 +14,24 @@ def onIrc_JOIN(self, irc, prefix, params):
             if 'hostmask' in BYTEBOT_PLUGIN_CONFIG['autoop'].keys():
                 if channel in BYTEBOT_PLUGIN_CONFIG['autoop']['hostmask'].keys():
                     if prefix in BYTEBOT_PLUGIN_CONFIG['autoop']['hostmask'][channel]:
-                        print("Giving user %s +o on channel %s" % (prefix, channel))
+                        log.msg("Giving user %s +o on channel %s" % 
+                                (prefix, channel), level=LOG_INFO)
                         irc.mode(channel, True, 'o', user=user)
                         irc.msg(channel, "Hey, %s, it seems like you're a nice guy. Let me op you hard" % user)
                     if user in BYTEBOT_PLUGIN_CONFIG['autoop']['name'][channel]:
-                        print("Giving user %s +o on channel %s" % (user, channel))
+                        log.msg("Giving user %s +o on channel %s" % 
+                                (user, channel), level=LOG_INFO)
                         irc.mode(channel, True, 'o', user=user)
                         irc.msg(channel, "Hey, %s, it seems like you're a nice guy. Let me op you hard" % user)
                     else:
-                        print("User %s not in autoop list %s" % (prefix, channel))
+                        log.msg("User %s not in autoop list %s" % 
+                                (prefix, channel), level=LOG_INFO)
                 else:
-                    print("Channel name %s not in bytebot_config.py" % channel)
+                    log.msg("Channel name %s not in bytebot_config.py" % 
+                            channel, level=LOG_WARN)
             else:
-                print("BYTEBOT_PLUGIN_CONFIG in bytebot_config.py has no 'hostmask' section")
+                log.msg("BYTEBOT_PLUGIN_CONFIG in bytebot_config.py has no 'hostmask' section",
+                       level=LOG_WARN)
         else:
-            print("BYTEBOT_PLUGIN_CONFIG in bytebot_config.py has no 'autoop' section")
+            log.msg("BYTEBOT_PLUGIN_CONFIG in bytebot_config.py has no 'autoop' section",
+                   level=LOG_WARN)

plugins/shorturl.py

@@ -6,13 +6,14 @@
 import re
 
 from plugins.plugin import Plugin
-from bs4 import BeautifulSoup
+from bs4            import BeautifulSoup
+from twisted.python import log
 
 from bytebot_config import BYTEBOT_HTTP_TIMEOUT, BYTEBOT_HTTP_MAXSIZE
 
 class shorturl(Plugin):
     def googl(self, url):
-        print("Shortening URL %s" % url)
+        log.msg("Shortening URL %s" % url)
 
         post_url = 'https://www.googleapis.com/urlshortener/v1/url'
         postdata = {'longUrl': url}

plugins/usercount.py

@@ -2,8 +2,10 @@
 # -*- coding: utf-8 -*-
 
 from plugins.plugin import Plugin
+from twisted.python import log
+from bytebot_log    import LOG_WARN
 
 class usercount(Plugin):
     def __init__(self):
-        print("Not implemented yet")
+        log.msg("Usercount not implemented yet", level=LOG_WARN)
         pass