From 2259e9d8b6bec2dd81966915791113acd5842900 Mon Sep 17 00:00:00 2001
From: Jeremy Fincher <jemfinch@users.sourceforge.net>
Date: Tue, 10 Aug 2004 07:39:23 +0000
Subject: [PATCH] Added log.stat, supybot.log.statistics, and changed some
 statistic-keeping functions over to use log.stat.

---
 src/asyncoreDrivers.py | 3 +--
 src/callbacks.py       | 4 ++--
 src/drivers.py         | 8 ++++++++
 src/log.py             | 9 +++++++++
 src/socketDrivers.py   | 4 +---
 src/twistedDrivers.py  | 3 +--
 6 files changed, 22 insertions(+), 9 deletions(-)

diff --git a/src/asyncoreDrivers.py b/src/asyncoreDrivers.py
index b5c1eafcf..673c34654 100644
--- a/src/asyncoreDrivers.py
+++ b/src/asyncoreDrivers.py
@@ -106,8 +106,7 @@ class AsyncoreDriver(asynchat.async_chat, drivers.ServersMixin):
 
     def found_terminator(self):
         start = time.time()
-        msg = ircmsgs.IrcMsg(self.buffer)
-        #log.debug('Time to parse IrcMsg: %s', time.time()-start)
+        msg = drivers.parseMsg(self.buffer)
         self.buffer = ''
         self.irc.feedMsg(msg)
 
diff --git a/src/callbacks.py b/src/callbacks.py
index a369257d3..9b1c51782 100644
--- a/src/callbacks.py
+++ b/src/callbacks.py
@@ -299,7 +299,7 @@ def tokenize(s, brackets=None, channel=None):
         return Tokenizer(tokens).tokenize(s)
     except ValueError, e:
         raise SyntaxError, str(e)
-    #log.debug('tokenize took %s seconds.' % (time.time() - start))
+    log.stat('tokenize took %s seconds.' % (time.time() - start))
 
 def getCommands(tokens):
     """Given tokens as output by tokenize, returns the command names."""
@@ -911,7 +911,7 @@ class Privmsg(irclib.IrcCallback):
         start = time.time()
         method(irc, msg, *L)
         elapsed = time.time() - start
-        self.log.debug('%s took %s seconds', name, elapsed)
+        log.stat('%s took %s seconds', name, elapsed)
 
     def registryValue(self, name, channel=None, value=True):
         plugin = self.name()
diff --git a/src/drivers.py b/src/drivers.py
index 6f28d8ded..9042838df 100644
--- a/src/drivers.py
+++ b/src/drivers.py
@@ -40,6 +40,7 @@ import supybot.fix as fix
 import re
 import os
 import sys
+import time
 
 import supybot.log as supylog
 import supybot.conf as conf
@@ -172,6 +173,7 @@ class Log(object):
     critical = staticmethod(supylog.critical)
     timestamp = staticmethod(supylog.timestamp)
     exception = staticmethod(supylog.exception)
+    stat = staticmethod(supylog.stat)
 
 log = Log()
         
@@ -195,4 +197,10 @@ def newDriver(irc, moduleName=None):
     irc.driver = driver
     return driver
 
+def parseMsg(s):
+    start = time.time()
+    msg = ircmsgs.IrcMsg(s)
+    log.stat('Time to parse IrcMsg: %s', time.time()-start)
+    return msg
+
 # vim:set shiftwidth=4 tabstop=8 expandtab textwidth=78:
diff --git a/src/log.py b/src/log.py
index 2cae71dd1..1f6303b27 100644
--- a/src/log.py
+++ b/src/log.py
@@ -162,6 +162,10 @@ error = _logger.error
 critical = _logger.critical
 exception = _logger.exception
 
+def stat(*args):
+    level = conf.supybot.log.statistics()
+    _logger.log(level, *args)
+    
 setLevel = _logger.setLevel
 
 atexit.register(logging.shutdown)
@@ -276,6 +280,11 @@ conf.registerGlobalValue(conf.supybot.log, 'level',
     LogLevel(logging.INFO, """Determines what the minimum priority level logged
     will be.  Valid values are DEBUG, INFO, WARNING, ERROR, and CRITICAL, in
     order of increasing priority."""))
+conf.registerGlobalValue(conf.supybot.log, 'statistics',
+    ValidLogLevel(logging.DEBUG, """Determines what level statistics reporting
+    is to be logged at.  Mostly, this just includes, for instance, the time it
+    took to parse a message, process a command, etc.  You probably don't care
+    about this."""))
 conf.registerGlobalValue(conf.supybot.log, 'stdout',
     registry.Boolean(True, """Determines whether the bot will log to
     stdout."""))
diff --git a/src/socketDrivers.py b/src/socketDrivers.py
index cec50a2fa..f1ebf9504 100644
--- a/src/socketDrivers.py
+++ b/src/socketDrivers.py
@@ -105,9 +105,7 @@ class SocketDriver(drivers.IrcDriver, drivers.ServersMixin):
             lines = self.inbuffer.split('\n')
             self.inbuffer = lines.pop()
             for line in lines:
-                start = time.time()
-                msg = ircmsgs.IrcMsg(line)
-                #log.debug('Time to parse IrcMsg: %s', time.time()-start)
+                msg = drivers.parseMsg(line)
                 self.irc.feedMsg(msg)
         except socket.timeout:
             pass
diff --git a/src/twistedDrivers.py b/src/twistedDrivers.py
index cc1ee7458..40a44f985 100644
--- a/src/twistedDrivers.py
+++ b/src/twistedDrivers.py
@@ -60,8 +60,7 @@ class SupyIrcProtocol(LineReceiver):
 
     def lineReceived(self, line):
         start = time.time()
-        msg = ircmsgs.IrcMsg(line)
-        #log.debug('Time to parse IrcMsg: %s', time.time()-start)
+        msg = drivers.parseMsg(line)
         self.irc.feedMsg(msg)
 
     def checkIrcForMsgs(self):