[Checkins] SVN: zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/ first shot at tracelog extensions.
Alex Smith
asmith at zope.com
Fri Sep 5 14:04:16 EDT 2008
Log message for revision 90883:
first shot at tracelog extensions.
Changed:
U zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/README.txt
A zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/interfaces.py
U zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/tests.py
U zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/tracelog.py
-=-
Modified: zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/README.txt
===================================================================
--- zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/README.txt 2008-09-05 17:57:43 UTC (rev 90882)
+++ zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/README.txt 2008-09-05 18:04:15 UTC (rev 90883)
@@ -114,3 +114,70 @@
C 21651664 2008-09-02T13:59:02
A 21651664 2008-09-02T13:59:02 200 ?
E 21651664 2008-09-02T13:59:02 Error: iteration over non-sequence
+
+Let's clean up before moving on.
+
+ >>> faux_app.app_hook = None
+
+
+Tracelog Extensions
+===================
+
+Additional information can be written to the trace log through the use of
+extensions. Extensions can be registered as named-utilities for any of the
+trace points mentioned above.
+
+ >>> import zc.zservertracelog.interfaces
+ >>> import zope.component
+ >>> import zope.interface
+
+ >>> site_manager = zope.component.getSiteManager()
+
+Extensions implement one or more of the sub-interfaces of ``ITracer``. Here,
+we'll define a simple extension that just logs how many times it's been
+called.
+
+ >>> class CountTracer(object):
+ ...
+ ... count = 0
+ ...
+ ... def __call__(self, logger, trace_point):
+ ... self.count += 1
+ ... logger.log(
+ ... 'count: %s' % self.count, extension_id='counttracer')
+
+ >>> count_tracer = CountTracer()
+ >>> site_manager.registerUtility(
+ ... count_tracer,
+ ... zc.zservertracelog.interfaces.ITraceRequestStart,
+ ... 'example.CountTracer')
+
+Extensions appear in the log with the *X* prefix immediately after any trace
+point they are registered for.
+
+ >>> invokeRequest(req1)
+ B 17954544 2008-09-05T09:47:00 GET /test-req1
+ X 17954544 2008-09-05T09:47:00 counttracer count: 1
+ I 17954544 2008-09-05T09:47:00 0
+ C 17954544 2008-09-05T09:47:00
+ A 17954544 2008-09-05T09:47:00 200 ?
+ E 17954544 2008-09-05T09:47:00
+
+
+Removing an Extension
+---------------------
+
+Unregistering the utility removes the extension.
+
+ >>> site_manager.unregisterUtility(
+ ... count_tracer,
+ ... zc.zservertracelog.interfaces.ITraceRequestStart,
+ ... 'example.CountTracer')
+ True
+
+ >>> invokeRequest(req1)
+ B 21714736 2008-09-05T13:45:44 GET /test-req1
+ I 21714736 2008-09-05T13:45:44 0
+ C 21714736 2008-09-05T13:45:44
+ A 21714736 2008-09-05T13:45:44 200 ?
+ E 21714736 2008-09-05T13:45:44
Added: zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/interfaces.py
===================================================================
--- zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/interfaces.py (rev 0)
+++ zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/interfaces.py 2008-09-05 18:04:15 UTC (rev 90883)
@@ -0,0 +1,52 @@
+##############################################################################
+#
+# Copyright (c) 2008 Zope Corporation and Contributors.
+# All Rights Reserved.
+#
+# This software is subject to the provisions of the Zope Public License,
+# Version 2.1 (ZPL). A copy of the ZPL should accompany this distribution.
+# THIS SOFTWARE IS PROVIDED "AS IS" AND ANY AND ALL EXPRESS OR IMPLIED
+# WARRANTIES ARE DISCLAIMED, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
+# WARRANTIES OF TITLE, MERCHANTABILITY, AGAINST INFRINGEMENT, AND FITNESS
+# FOR A PARTICULAR PURPOSE.
+#
+##############################################################################
+"""tracelog interfaces
+"""
+__docformat__ = "reStructuredText"
+
+import zope.interface
+
+
+class ITraceLog(zope.interface.Interface):
+ """Logs records from writers."""
+
+ def log(msg=None, timestamp=None, extension_id=None):
+ """Write a message to the trace log."""
+
+
+class ITracer(zope.interface.Interface):
+ """Enters trace points."""
+
+ def __call__(logger, trace_point):
+ """Record an entry in the trace log."""
+
+
+class ITraceRequestStart(ITracer):
+ """Enters the *Request Start* trace point."""
+
+
+class ITraceRequestInputAcquired(ITracer):
+ """Enters the *Request Input Acquired* trace point."""
+
+
+class ITraceApplicationStart(ITracer):
+ """Enters the *Application Start* trace point."""
+
+
+class ITraceApplicationEnd(ITracer):
+ """Enters the *Application End* trace point."""
+
+
+class ITraceRequestEnd(ITracer):
+ """Enters the *Request End* trace point."""
Modified: zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/tests.py
===================================================================
--- zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/tests.py 2008-09-05 17:57:43 UTC (rev 90882)
+++ zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/tests.py 2008-09-05 18:04:15 UTC (rev 90883)
@@ -17,6 +17,7 @@
__docformat__ = "reStructuredText"
from zope.testing import doctest
+import StringIO
import re
import unittest
import zope.testing.renormalizing
Modified: zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/tracelog.py
===================================================================
--- zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/tracelog.py 2008-09-05 17:57:43 UTC (rev 90882)
+++ zc.zservertracelog/branches/alex-tracelog-extensions/src/zc/zservertracelog/tracelog.py 2008-09-05 18:04:15 UTC (rev 90883)
@@ -20,31 +20,79 @@
import datetime
import logging
import re
+import zc.zservertracelog.interfaces
import zope.app.appsetup.interfaces
import zope.component
import zope.server.http.httprequestparser
import zope.server.http.httpserverchannel
-logger = logging.getLogger('zc.tracelog')
+tracelog = logging.getLogger('zc.tracelog')
-def now():
- return datetime.datetime.now().replace(microsecond=0).isoformat()
+def _format_datetime(dt):
+ return dt.replace(microsecond=0).isoformat()
+
+
+def _run_trace_extensions(trace_point, logger):
+ tracers = zope.component.getUtilitiesFor(trace_point)
+ for tname, tracer in tracers:
+ tracer(logger, trace_point)
+
+
+class TraceLog(object):
+ zope.interface.implements(zc.zservertracelog.interfaces.ITraceLog)
+
+ def __init__(self, channel):
+ self.channel_id = id(channel)
+
+ # this implementation adds a `trace_code` option which is meant to be
+ # used internally and not for use by extensions.
+ def log(
+ self, msg=None, timestamp=None, extension_id=None, trace_code=None):
+
+ if timestamp is None:
+ timestamp = datetime.datetime.now()
+
+ if not trace_code:
+ trace_code = 'X'
+
+ if trace_code == 'X' and extension_id is None:
+ raise ValueError('extension_id is required')
+
+ entry = '%s %s %s' % (
+ trace_code, self.channel_id, _format_datetime(timestamp))
+
+ if extension_id:
+ entry += ' %s' % extension_id
+
+ if msg:
+ entry += ' %s' % msg
+
+ tracelog.info(entry)
+
+
class Parser(zope.server.http.httprequestparser.HTTPRequestParser):
def __init__(self, x):
- self._Channel__B = now()
+ self._Channel__B = datetime.datetime.now()
zope.server.http.httprequestparser.HTTPRequestParser.__init__(self, x)
+
class Channel(zope.server.http.httpserverchannel.HTTPServerChannel):
parser_class = Parser
def handle_request(self, parser):
- logger.info("B %s %s %s %s", id(self), parser.__B,
- parser.command, parser.path)
- logger.info("I %s %s %s", id(self), now(),
- parser.content_length)
+ logger = TraceLog(self)
+ logger.log(
+ '%s %s' % (parser.command, parser.path),
+ parser.__B,
+ trace_code='B')
+ _run_trace_extensions(
+ zc.zservertracelog.interfaces.ITraceRequestStart, logger)
+ logger.log(str(parser.content_length), trace_code='I')
+ _run_trace_extensions(
+ zc.zservertracelog.interfaces.ITraceRequestInputAcquired, logger)
zope.server.http.httpserverchannel.HTTPServerChannel.handle_request(
self, parser)
@@ -54,9 +102,15 @@
channel_class = Channel
+ def __init__(self, *args, **kwargs):
+ super(Server, self).__init__(*args, **kwargs)
+
def executeRequest(self, task):
"""Overrides HTTPServer.executeRequest()."""
- logger.info("C %s %s", id(task.channel), now())
+ logger = TraceLog(task.channel)
+ logger.log(trace_code='C')
+ _run_trace_extensions(
+ zc.zservertracelog.interfaces.ITraceApplicationStart, logger)
env = task.getCGIEnvironment()
env['wsgi.input'] = task.request_data.getBodyStream()
@@ -73,8 +127,12 @@
try:
response = self.application(env, start_response)
except Exception, v:
- logger.info("A %s %s Error: %s", id(task.channel), now(), v)
- logger.info("E %s %s", id(task.channel), now())
+ logger.log('Error: %s' % v, trace_code='A')
+ _run_trace_extensions(
+ zc.zservertracelog.interfaces.ITraceApplicationEnd, logger)
+ logger.log(trace_code='E')
+ _run_trace_extensions(
+ zc.zservertracelog.interfaces.ITraceRequestEnd, logger)
raise
else:
accumulated_headers = getattr(task, 'accumulated_headers') or ()
@@ -85,28 +143,40 @@
length = length[0]
else:
length = '?'
- logger.info("A %s %s %s %s", id(task.channel), now(),
- getattr(task, 'status', '?'), length)
+
+ logger.log(
+ '%s %s' % (getattr(task, 'status', '?'), length),
+ trace_code='A')
+ _run_trace_extensions(
+ zc.zservertracelog.interfaces.ITraceApplicationEnd, logger)
+
try:
task.write(response)
except Exception, v:
- logger.info("E %s %s Error: %s", id(task.channel), now(), v)
+ logger.log('Error: %s' % v, trace_code='E')
+ _run_trace_extensions(
+ zc.zservertracelog.interfaces.ITraceRequestEnd, logger)
raise
else:
- logger.info("E %s %s", id(task.channel), now())
+ logger.log(trace_code='E')
+ _run_trace_extensions(
+ zc.zservertracelog.interfaces.ITraceRequestEnd, logger)
+
http = servertype.ServerType(
Server,
WSGIPublisherApplication,
CommonAccessLogger,
8080, True)
+
pmhttp = servertype.ServerType(
wsgihttpserver.PMDBWSGIHTTPServer,
WSGIPublisherApplication,
CommonAccessLogger,
8013, True)
+
@zope.component.adapter(zope.app.appsetup.interfaces.IProcessStartingEvent)
def started(event):
- logger.info("S 0 %s", now())
+ tracelog.info('S 0 %s', _format_datetime(datetime.datetime.now()))
More information about the Checkins
mailing list