Refactored _getNextServer and friends as well as logging.

src/asyncoreDrivers.py

@@ -43,6 +43,7 @@ import asynchat
 import supybot.log as log
 import supybot.conf as conf
 import supybot.ircdb as ircdb
+import supybot.utils as utils
 import supybot.world as world
 import supybot.drivers as drivers
 import supybot.ircmsgs as ircmsgs
@@ -59,48 +60,30 @@ class AsyncoreRunnerDriver(drivers.IrcDriver):
             else:
                 asyncore.poll(timeout)
         except:
-            log.exception('Uncaught exception:')
+            drivers.log.exception('Uncaught exception:')
 
 
-class AsyncoreDriver(asynchat.async_chat, object):
+class AsyncoreDriver(asynchat.async_chat, drivers.ServersMixin):
     def __init__(self, irc, servers=()):
         asynchat.async_chat.__init__(self)
+        drivers.ServersMixin.__init__(self, irc, servers=servers)
         self.irc = irc
         self.buffer = ''
-        self.servers = servers 
-        self.networkGroup = conf.supybot.networks.get(self.irc.network)
         self.set_terminator('\n')
         try:
             server = self._getNextServer()
             sock = utils.getSocket(server[0])
             self.set_socket(sock)
-            log.info('Connecting to %s.', self.currentServer)
+            drivers.log.connect(self.currentServer)
             self.connect(server)
         except socket.error, e:
-            log.warning('Error connecting to %s: %s', self.currentServer, e)
+            drivers.log.connectError(self.currentServer, e)
             self.reconnect(wait=True)
 
-    def _getServers(self):
-        # We do this, rather than itertools.cycle the servers in __init__,
-        # because otherwise registry updates given as setValues or sets
-        # wouldn't be visible until a restart.
-        return self.networkGroup.servers()[:] # Be sure to copy!
-
-    def _getNextServer(self):
-        if not self.servers:
-            self.servers = self._getServers()
-        assert self.servers, 'Servers value for %s is empty.' % \
-                             self.networkGroup.name
-        server = self.servers.pop(0)
-        self.currentServer = '%s:%s' % server
-        return server
-        
     def _scheduleReconnect(self, at=60):
         when = time.time() + at
         if not world.dying:
-            whenS = log.timestamp(when)
+            drivers.log.reconnect(self.irc.network, when)
-            log.info('Scheduling reconnect to %s at %s',
-                     self.currentServer, whenS)
         def makeNewDriver():
             self.irc.reset()
             driver = self.__class__(self.irc, servers=self.servers)
@@ -137,7 +120,7 @@ class AsyncoreDriver(asynchat.async_chat, object):
         pass
 
     def die(self):
-        log.info('Driver for %s dying.', self.irc)
+        drivers.log.die(self.irc)
         self.close()
 
 try:

src/drivers.py

@@ -41,7 +41,7 @@ import re
 import os
 import sys
 
-import supybot.log as log
+import supybot.log as supylog
 import supybot.conf as conf
 import supybot.ansi as ansi
 import supybot.ircmsgs as ircmsgs
@@ -70,6 +70,28 @@ class IrcDriver(object):
     def name(self):
         return repr(self)
 
+class ServersMixin(object):
+    def __init__(self, irc, servers=()):
+        self.networkGroup = conf.supybot.networks.get(irc.network)
+        self.servers = servers
+        super(ServersMixin, self).__init__(irc)
+        
+    def _getServers(self):
+        # We do this, rather than itertools.cycle the servers in __init__,
+        # because otherwise registry updates given as setValues or sets
+        # wouldn't be visible until a restart.
+        return self.networkGroup.servers()[:] # Be sure to copy!
+
+    def _getNextServer(self):
+        if not self.servers:
+            self.servers = self._getServers()
+        assert self.servers, 'Servers value for %s is empty.' % \
+                             self.networkGroup._name
+        server = self.servers.pop(0)
+        self.currentServer = '%s:%s' % server
+        return server
+        
+
 def empty():
     """Returns whether or not the driver loop is empty."""
     return (len(_drivers) + len(_newDrivers)) == 0
@@ -111,6 +133,47 @@ def run():
             del _drivers[name]
         _drivers[name] = driver
 
+class Log(object):
+    """This is used to have a nice, consistent interface for drivers to use."""
+    def connect(self, server):
+        self.info('Connecting to %s.', server)
+
+    def connectError(self, server, e):
+        if isinstance(e, Exception):
+            e = utils.exnToString(e)
+        self.warning('Error connecting to %s: %s', server, e)
+
+    def disconnect(self, server, e=None):
+        if e:
+            if isinstance(e, Exception):
+                e = utils.exnToString(e)
+            self.warning('Disconnect from %s: %s.', server, e)
+        else:
+            self.info('Disconnect from %s.', server)
+
+    def reconnect(self, network, when=None):
+        s = 'Reconnecting to %s' % network
+        if when is not None:
+            if not isinstance(when, basestring):
+                when = self.timestamp(when)
+            s += ' at %s.' % when
+        else:
+            s += '.'
+        self.info(s)
+
+    def die(self, irc):
+        self.info('Driver for %s dying.', irc)
+
+    debug = staticmethod(supylog.debug)
+    info = staticmethod(supylog.info)
+    warning = staticmethod(supylog.warning)
+    error = staticmethod(supylog.warning)
+    critical = staticmethod(supylog.critical)
+    timestamp = staticmethod(supylog.timestamp)
+    exception = staticmethod(supylog.exception)
+
+log = Log()
+        
 def newDriver(irc, moduleName=None):
     """Returns a new driver for the given server using the irc given and using
     conf.supybot.driverModule to determine what driver to pick."""

src/socketDrivers.py

@@ -54,11 +54,11 @@ import supybot.ircmsgs as ircmsgs
 import supybot.schedule as schedule
 
 reconnectWaits = (0, 60, 300)
-class SocketDriver(drivers.IrcDriver):
+class SocketDriver(drivers.IrcDriver, drivers.ServersMixin):
     def __init__(self, irc):
         self.irc = irc
+        drivers.ServersMixin.__init__(self, irc)
         drivers.IrcDriver.__init__(self) # Must come after setting irc.
-        self.networkGroup = conf.supybot.networks.get(self.irc.network)
         self.servers = ()
         self.eagains = 0
         self.inbuffer = ''
@@ -68,27 +68,11 @@ class SocketDriver(drivers.IrcDriver):
         self.reconnectWaits = reconnectWaits
         self.connect()
 
-    def _getServers(self):
-        # We do this, rather than itertools.cycle the servers in __init__,
-        # because otherwise registry updates given as setValues or sets
-        # wouldn't be visible until a restart.
-        return self.networkGroup.servers()[:] # Be sure to copy!
-
-    def _getNextServer(self):
-        if not self.servers:
-            self.servers = self._getServers()
-        assert self.servers, 'Servers value for %s is empty.' % \
-                             self.networkGroup.name
-        server = self.servers.pop(0)
-        self.currentServer = '%s:%s' % server
-        return server
-        
     def _handleSocketError(self, e):
         # (11, 'Resource temporarily unavailable') raised if connect
         # hasn't finished yet.  We'll keep track of how many we get.
         if e.args[0] != 11 and self.eagains > 120:
-            log.warning('Disconnect from %s: %s.',
+            drivers.log.disconnect(self.currentServer, e)
-                        self.currentServer, e.args[1])
             self.reconnect(wait=True)
         else:
             log.debug('Got EAGAIN, current count: %s.', self.eagains)
@@ -137,26 +121,24 @@ class SocketDriver(drivers.IrcDriver):
         
     def reconnect(self, wait=False, reset=True):
         server = self._getNextServer()
-        if reset:
-            log.debug('Resetting %s.', self.irc)
-            self.irc.reset()
-        else:
-            log.debug('Not resetting %s.', self.irc)
         if self.connected:
-            log.info('Reconnect called on driver for %s.', self.irc)
+            drivers.log.reconnect(self.irc.network)
             self.conn.close()
         elif not wait:
-            log.info('Connecting to %s.', self.currentServer)
+            drivers.log.connect(self.currentServer)
+        if reset:
+            drivers.log.debug('Resetting %s.', self.irc)
+            self.irc.reset()
+        else:
+            drivers.log.debug('Not resetting %s.', self.irc)
         self.connected = False
         if wait:
-            log.info('Reconnect to %s waiting.', self.currentServer)
             self._scheduleReconnect()
             return
         try:
             self.conn = utils.getSocket(server[0])
         except socket.error, e:
-            log.warning('Error connecting to %s: %s',
+            drivers.log.connectError(self.currentServer, e)
-                        self.currentServer, e.args[1])
             self.reconnect(wait=True)
             return
         # We allow more time for the connect here, since it might take longer.
@@ -172,37 +154,35 @@ class SocketDriver(drivers.IrcDriver):
                 now = time.time()
                 when = now + 60
                 whenS = log.timestamp(when)
-                log.info('Connection in progress, scheduling connectedness '
+                drivers.log.debug('Connection in progress, scheduling '
-                         'check for %s', whenS)
+                                  'connectedness check for %s', whenS)
                 schedule.addEvent(self._checkAndWriteOrReconnect, when)
             else:
-                log.warning('Error connecting to %s: %s', self.currentServer,e)
+                drivers.log.connectError(self.currentServer, e)
                 self.reconnect(wait=True)
             return
         self.connected = True
         self.reconnectWaitPeriodsIndex = 0
 
     def _checkAndWriteOrReconnect(self):
-        log.debug('Checking whether we are connected.')
+        drivers.log.debug('Checking whether we are connected.')
         (_, w, _) = select.select([], [self.conn], [], 0)
         if w:
-            log.info('Socket is writable, it might be connected.')
+            drivers.log.debug('Socket is writable, it might be connected.')
             self.connected = True
             self.reconnectWaitPeriodsIndex = 0
         else:
-            log.warning('Error connecting to %s: Timed out.',self.currentServer)
+            drivers.log.connectError(self.currentServer, 'Timed out')
             self.reconnect()
 
     def _scheduleReconnect(self):
         when = time.time() + self.reconnectWaits[self.reconnectWaitsIndex]
         if not world.dying:
-            whenS = log.timestamp(when)
+            drivers.log.reconnect(self.irc.network, when)
-            log.info('Scheduling reconnect to %s at %s',
-                     self.irc.network, whenS)
         schedule.addEvent(self.reconnect, when)
 
     def die(self):
-        log.info('Driver for %s dying.', self.irc)
+        drivers.log.die(self.irc)
         self.conn.close()
         # self.irc.die() Kill off the ircs yourself, jerk!
 

src/twistedDrivers.py

@@ -50,7 +50,7 @@ class TwistedRunnerDriver(drivers.IrcDriver):
         try:
             reactor.iterate(conf.supybot.drivers.poll())
         except:
-            log.exception('Uncaught exception outside reactor:')
+            drivers.log.exception('Uncaught exception outside reactor:')
 
 class SupyIrcProtocol(LineReceiver):
     delimiter = '\n'
@@ -74,7 +74,7 @@ class SupyIrcProtocol(LineReceiver):
     def connectionLost(self, failure):
         self.mostRecentCall.cancel()
         self.irc.reset()
-        log.warning(failure.getErrorMessage())
+        drivers.log.disconnect(self.currentServer, errorMsg(failure))
 
     def connectionMade(self):
         self.irc.reset()
@@ -82,44 +82,33 @@ class SupyIrcProtocol(LineReceiver):
         self.irc.driver = self
 
     def die(self):
-        log.info('Driver for %s dying.', self.irc)
+        drivers.log.die(self.irc)
         self.factory.continueTrying = False
         self.transport.loseConnection()
 
     def reconnect(self):
+        drivers.log.reconnect(self.irc.network)
         self.transport.loseConnection()
 
+def errorMsg(reason):
+    return reason.getErrorMessage()
 
-class SupyReconnectingFactory(ReconnectingClientFactory):
+class SupyReconnectingFactory(ReconnectingClientFactory, drivers.ServersMixin):
     maxDelay = 300
     protocol = SupyIrcProtocol
     def __init__(self, irc):
         self.irc = irc
-        self.networkGroup = conf.supybot.networks.get(self.irc.network)
+        drivers.ServersMixin.__init__(self, irc)
-        self.servers = ()
         (server, port) = self._getNextServer()
         reactor.connectTCP(server, port, self)
 
-    def _getServers(self):
-        # We do this, rather than itertools.cycle the servers in __init__,
-        # because otherwise registry updates given as setValues or sets
-        # wouldn't be visible until a restart.
-        return self.networkGroup.servers()[:] # Be sure to copy!
-
-    def _getNextServer(self):
-        if not self.servers:
-            self.servers = self._getServers()
-        assert self.servers, 'Servers value for %s is empty.' % \
-                             self.networkGroup.name
-        server = self.servers.pop(0)
-        self.currentServer = '%s:%s' % server
-        return server
-        
     def clientConnectionFailed(self, connector, r):
+        drivers.log.connectError(self.currentServer, errorMsg(r))
         (connector.host, connector.port) = self._getNextServer()
         ReconnectingClientFactory.clientConnectionFailed(self, connector, r)
 
     def clientConnectionLost(self, connector, r):
+        drivers.log.disconnect(self.currentServer, errorMsg(r))
         (connector.host, connector.port) = self._getNextServer()
         ReconnectingClientFactory.clientConnectionLost(self, connector, r)