/dozer/logview.py

  1import logging
  2import os
  3import re
  4import time
  5import itertools
  6import traceback
  7import sys
  8
  9from mako.lookup import TemplateLookup
 10from paste import urlparser
 11from paste.util.converters import asbool
 12from webob import Request, Response
 13from webob import exc
 14
 15try:
 16    import thread
 17    import threading
 18except ImportError:
 19    thread = None
 20
 21
 22here_dir = os.path.dirname(os.path.abspath(__file__))
 23
 24
 25class Logview(object):
 26    def __init__(self, app, config=None, loglevel='DEBUG', **kwargs):
 27        """Stores logging statements per request, and includes a bar on
 28        the page that shows the logging statements
 29
 30        ''loglevel''
 31            Default log level for messages that should be caught.
 32
 33            Note: the root logger's log level also matters!  If you do
 34            logging.getLogger('').setLevel(logging.INFO), no DEBUG messages
 35            will make it to Logview's handler anyway.
 36
 37        Config can contain optional additional loggers and the colors
 38        they should be highlighted (in an ini file)::
 39
 40            logview.sqlalchemy = #ff0000
 41
 42        Or if passing a dict::
 43
 44            app = Logview(app, {'logview.sqlalchemy':'#ff0000'})
 45
 46        """
 47        self.app = app
 48        tmpl_dir = os.path.join(here_dir, 'templates')
 49        self.mako = TemplateLookup(directories=[tmpl_dir])
 50
 51        self.log_colors = {}
 52        for key, val in itertools.chain(config.iteritems(),
 53                                        kwargs.iteritems()):
 54            if key.startswith('logview.'):
 55                self.log_colors[key[len('logview.'):]] = val
 56
 57        self.traceback_colors = {}
 58        for key, val in itertools.chain(config.iteritems(),
 59                                        kwargs.iteritems()):
 60            if key.startswith('traceback.'):
 61                self.traceback_colors[key[len('traceback.'):]] = val
 62
 63        self.logger = logging.getLogger(__name__)
 64        self.loglevel = getattr(logging, loglevel)
 65
 66        self.keep_tracebacks = asbool(kwargs.get(
 67            'keep_tracebacks', config.get(
 68                'keep_tracebacks', RequestHandler.keep_tracebacks)))
 69        self.keep_tracebacks_limit = int(kwargs.get(
 70            'keep_tracebacks_limit', config.get(
 71                'keep_tracebacks_limit', RequestHandler.keep_tracebacks_limit)))
 72        self.skip_first_n_frames = int(kwargs.get(
 73            'skip_first_n_frames', config.get(
 74                'skip_first_n_frames', RequestHandler.skip_first_n_frames)))
 75        self.skip_last_n_frames = int(kwargs.get(
 76            'skip_last_n_frames', config.get(
 77                'skip_last_n_frames', RequestHandler.skip_last_n_frames)))
 78
 79        reqhandler = RequestHandler()
 80        reqhandler.setLevel(self.loglevel)
 81        reqhandler.keep_tracebacks = self.keep_tracebacks
 82        reqhandler.keep_tracebacks_limit = self.keep_tracebacks_limit
 83        reqhandler.skip_first_n_frames = self.skip_first_n_frames
 84        reqhandler.skip_last_n_frames = self.skip_last_n_frames
 85        logging.getLogger('').addHandler(reqhandler)
 86        self.reqhandler = reqhandler
 87
 88    def __call__(self, environ, start_response):
 89        if thread:
 90            tok = thread.get_ident()
 91        else:
 92            tok = None
 93
 94        req = Request(environ)
 95        start = time.time()
 96        self.logger.log(self.loglevel, 'request started')
 97        response = req.get_response(self.app)
 98        self.logger.log(self.loglevel, 'request finished')
 99        tottime = time.time() - start
100        reqlogs = self.reqhandler.pop_events(tok)
101        if 'content-type' in response.headers and \
102           response.headers['content-type'].startswith('text/html'):
103            logbar = self.render('/logbar.mako', events=reqlogs,
104                                 logcolors=self.log_colors,
105                                 traceback_colors=self.traceback_colors,
106                                 tottime=tottime, start=start)
107            logbar = logbar.encode('ascii', 'xmlcharrefreplace')
108            parts = re.split(r'(<body[^>]*>)', response.body)
109            # parts = ['preamble', '<body ...>', 'text'] or just ['text']
110            # we want to insert our logbar after <body> (if it exists) and
111            # in front of text
112            response.body = ''.join(parts[:-1] + [logbar] + parts[-1:])
113        return response(environ, start_response)
114
115    def render(self, name, **vars):
116        tmpl = self.mako.get_template(name)
117        return tmpl.render(**vars)
118
119
120class RequestHandler(logging.Handler):
121    """
122    A handler class which only records events if its set as active for
123    a given thread/process (request). Log history per thread must be
124    removed manually, preferably at the end of the request. A reference
125    to the RequestHandler instance should be retained for this access.
126
127    This handler otherwise works identically to a request-handler,
128    except that events are logged to specific 'channels' based on
129    thread id when available.
130
131    """
132
133    keep_tracebacks = False
134    keep_tracebacks_limit = 20 # too many of these make things very very slow
135    skip_first_n_frames = 0
136    skip_last_n_frames = 6 # number of frames beween logger.log() and our emit()
137                           # determined empirically on Python 2.6
138
139    def __init__(self):
140        """Initialize the handler."""
141        logging.Handler.__init__(self)
142        self.buffer = {}
143
144    def emit(self, record):
145        """Emit a record.
146
147        Append the record. If shouldFlush() tells us to, call flush() to process
148        the buffer.
149        """
150        self.buffer.setdefault(record.thread, []).append(record)
151        if self.keep_tracebacks and (not self.keep_tracebacks_limit or
152                len(self.buffer[record.thread]) < self.keep_tracebacks_limit):
153            f = sys._getframe(self.skip_last_n_frames)
154            record.traceback = traceback.format_list(
155                traceback.extract_stack(f)[self.skip_first_n_frames:])
156
157    def pop_events(self, thread_id):
158        """Return all the events logged for particular thread"""
159        if thread_id in self.buffer:
160            return self.buffer.pop(thread_id)
161        else:
162            return []
163
164    def flush(self):
165        """Kills all data in the buffer"""
166        self.buffer = {}
167    
168    def close(self):
169        """Close the handler.
170
171        This version just flushes and chains to the parent class' close().
172        """
173        self.flush()
174        logging.Handler.close(self)