Metadata-Version: 1.0
Name: zc.zservertracelog
Version: 1.1.4
Summary: Zope 3 tracelog implementation for zserver
Home-page: http://pypi.python.org/pypi/zc.zservertracelog
Author: Zope Corporation and Contributors
Author-email: zope3-dev@zope.org
License: ZPL 2.1
Description: =======================
        Zope 3/ZServer tracelog
        =======================
        
        This package implements a Zope2-style (extended) tracelog.  A tracelog
        is a kind of access log that records several low-level events for each
        request.  Each log entry starts with a record type, a request
        identifier and the time.  Some log records have additional data.
        
        
        Trace Codes
        ===========
        
        - Request begins:
        
        B -1214390740 2007-04-27T20:16:55.582940 GET /
        
        Includes the request method and path.
        
        - Got request input:
        
        I -1214390740 2007-04-27T20:16:55.605791 0
        
        Includes the request content length.
        
        - Entered application thread:
        
        C -1214390740 2007-04-27T20:16:55.703829
        
        - Application done:
        
        A -1223774356 2007-04-27T20:16:55.890371 500 84
        
        Includes the response content length.
        
        - Request done:
        
        E -1223774356 2007-04-27T20:16:55.913855
        
        In addition, application startup is logged with an 'S' record:
        
        S 0 2007-04-27T20:24:29.013922
        
        Tracelog extension records are prefixed with a '-':
        
        - -1223774356 2008-09-12T15:51:05.559302 zc.example.extension message
        
        To create a trace log, include the zc.zservertracelog package in your
        site ZCML configuration.  Also, define a logger section in zope.conf::
        
        <logger>
        name zc.zservertracelog
        propagate false
        
        <logfile>
        format %(message)s
        path /home/jim/p/zc.zservertracelog/dev/trace.log
        </logfile>
        
        </logger>
        
        Where, of course, you'll need to specify a log file path.
        
        The analysis script, tracereport, can be used to analyze the trace
        log. I recommend the html output option.
        
        
        Detailed Documentation
        **********************
        
        
        ================
        ZServer TraceLog
        ================
        
        A tracelog is a kind of access log that records several low-level events for
        each request.  Each log entry starts with a record type, a request identifier
        and the time.  Some log records have additional data.
        
        >>> import zc.zservertracelog.tracelog
        >>> import zope.app.appsetup.interfaces
        
        For these examples, we'll add a log handler that outputs to standard out.
        
        >>> import logging
        >>> import sys
        >>> stdout_handler = logging.StreamHandler(sys.stdout)
        
        The logger's name is not the package name, but "zc.tracelog" for backward
        compatability.
        
        >>> logger = logging.getLogger('zc.tracelog')
        >>> logger.setLevel(logging.INFO)
        >>> logger.addHandler(stdout_handler)
        
        
        Server Startup
        ==============
        
        There is an event handler to log when the Z server starts.
        
        >>> zc.zservertracelog.tracelog.started(
        ...     zope.app.appsetup.interfaces.ProcessStarting())
        S 0 2008-08-26 11:55:00.000000
        
        
        Tracing Applications
        ====================
        
        The tracelog machinery is implemented as a WSGI layer, so we'll pass a fake
        WSGI application to tracelog for these examples.
        
        >>> faux_app = FauxApplication()
        
        Now, let's create an instance of the tracelog server.
        
        >>> addr, port = '127.0.0.1', 12345
        
        >>> trace_server = zc.zservertracelog.tracelog.Server(
        ...     faux_app, None, addr, port)
        
        Let's also define a convenience function for processing requests.
        
        >>> def invokeRequest(req):
        ...     channel = trace_server.channel_class(trace_server, None, addr)
        ...     channel.received(req)
        
        Process a simple request.
        
        >>> req1 = """\
        ... GET /test-req1 HTTP/1.1
        ... Host: www.example.com
        ...
        ... """
        
        >>> invokeRequest(req1)
        B 23423600 2008-08-27 10:54:08.000000 GET /test-req1
        I 23423600 2008-08-27 10:54:08.000000 0
        C 23423600 2008-08-27 10:54:08.000000
        A 23423600 2008-08-27 10:54:08.000000 200 ?
        E 23423600 2008-08-27 10:54:08.000000
        
        
        Application Errors
        ==================
        
        The tracelog will also log application errors.  To show this, we'll set up
        our test application to raise an error when called.
        
        >>> def app_failure(*args, **kwargs):
        ...     raise Exception('oh noes!')
        >>> faux_app.app_hook = app_failure
        
        Invoking the request produces log entries for every trace point, and the
        application error is written to the *Application End (A)* trace entry.
        
        >>> try:
        ...     invokeRequest(req1)
        ... except:
        ...     pass
        B 21663984 2008-09-02 11:19:26.000000 GET /test-req1
        I 21663984 2008-09-02 11:19:26.000000 0
        C 21663984 2008-09-02 11:19:26.000000
        A 21663984 2008-09-02 11:19:26.000000 Error: oh noes!
        E 21663984 2008-09-02 11:19:26.000000
        
        
        Response Errors
        ===============
        
        The tracelog also handles errors that can be generated when writing to the
        response.  To show this, we'll set up our test application to return a
        response that produces an error when written to.
        
        >>> def response_of_wrong_type(*args, **kwargs):
        ...     return object()
        >>> faux_app.app_hook = response_of_wrong_type
        
        Invoking the request produces log entries for every trace point, and the
        error is written to the *Request End (E)* trace entry.
        
        >>> try:
        ...     invokeRequest(req1)
        ... except:
        ...     pass
        B 21651664 2008-09-02 13:59:02.000000 GET /test-req1
        I 21651664 2008-09-02 13:59:02.000000 0
        C 21651664 2008-09-02 13:59:02.000000
        A 21651664 2008-09-02 13:59:02.000000 200 ?
        E 21651664 2008-09-02 13:59:02.000000 Error: iteration over non-sequence
        
        Let's clean up before moving on.
        
        >>> faux_app.app_hook = None
        
        
        Log Messages Containing Line Breaks
        ===================================
        
        Messages to the tracelog that contain newline characters will not split a log
        entry into multiple lines.
        
        >>> req2 = """\
        ... GET /test-req2/%0Aohnoes/ HTTP/1.1
        ... Host: www.example.com/linebreak
        ...
        ... """
        
        >>> invokeRequest(req2)
        B 21598352 2008-09-12 11:40:27.000000 GET /test-req2/\nohnoes/
        I 21598352 2008-09-12 11:40:27.000000 0
        C 21598352 2008-09-12 11:40:27.000000
        A 21598352 2008-09-12 11:40:27.000000 200 ?
        E 21598352 2008-09-12 11:40:27.000000
        
        
        Request Query Strings
        =====================
        
        The tracelog preserves request query strings.
        
        >>> req3 = """\
        ... GET /test-req3/?creature=unicorn HTTP/1.1
        ... Host: www.example.com/query-string
        ...
        ... """
        
        >>> invokeRequest(req3)
        B 21598352 2008-09-12 11:40:27.000000 GET /test-req3/?creature=unicorn
        I 21598352 2008-09-12 11:40:27.000000 0
        C 21598352 2008-09-12 11:40:27.000000
        A 21598352 2008-09-12 11:40:27.000000 200 ?
        E 21598352 2008-09-12 11:40:27.000000
        
        Empty query strings are also preserved.
        
        >>> req4 = """\
        ... GET /test-req4/? HTTP/1.1
        ... Host: www.example.com/empty-query-string
        ...
        ... """
        
        >>> invokeRequest(req4)
        B 21598352 2008-09-12 11:40:27.000000 GET /test-req4/?
        I 21598352 2008-09-12 11:40:27.000000 0
        C 21598352 2008-09-12 11:40:27.000000
        A 21598352 2008-09-12 11:40:27.000000 200 ?
        E 21598352 2008-09-12 11:40:27.000000
        
        
        Adding Additional Entries to the Trace Log
        ==========================================
        
        A tracelog object is added to the WSGI environment on each request.  This
        object implements ``ITraceLog`` and provides applications a method to add
        custom entries to the log.
        
        Here is an example application that adds a custom entry to the tracelog.
        
        >>> def noisy_app(environ, start_response):
        ...     logger = environ['zc.zservertracelog.interfaces.ITraceLog']
        ...     logger.log('beep! beep!')
        >>> faux_app.app_hook = noisy_app
        
        >>> invokeRequest(req1)
        B 21569456 2008-09-12 15:51:05.000000 GET /test-req1
        I 21569456 2008-09-12 15:51:05.000000 0
        C 21569456 2008-09-12 15:51:05.000000
        - 21569456 2008-09-12 15:51:05.000000 beep! beep!
        A 21569456 2008-09-12 15:51:05.000000 200 ?
        E 21569456 2008-09-12 15:51:05.000000
        
        
        =========
        Changes
        =========
        
        1.1.4 (2009-03-25)
        ------------------
        
        - put user names in access log
        
        
        1.1.3 (2009-03-25)
        ------------------
        
        - sub-second resolution in timestamps
        
        
        1.1.1 (2008-11-21)
        ------------------
        
        - switch back to logger name zc.tracelog to maintain backward compatibility.
        
        
        1.1.0 (2008-10-31)
        ------------------
        
        - fixed tracelog extension format so that it doesn't conflict with the Zope2
        trace code for server shutdown.
        
        - added *summary-only* and *summary-lines* options to tracereport.
        
        - added shading of alternating rows in tracereport table output.
        
        - fixed a documentation error for loghandler configuration.
        
        
        0.4 (2008-10-09)
        ----------------
        
        - added automated tests.
        
        - fixed bug where log entries could be split by messages containing newline
        characters.
        
        - added request query strings to log.
        
        - added the tracelog to the WSGI environment.
        
Keywords: zope3
Platform: UNKNOWN
