zc.zservertracelog 2.0.0

Zope 3 tracelog implementation for zserver

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.

To create a trace log, you need to:

• Include the zc.zservertracelog configuration in your site zcml file:

  <include package="zc.zservertracelog" />

• Define where messages to the ‘zc.tracelog’ logger should go. In your zope.conf file, use something like:

  <logger>
    name zc.tracelog
    propagate false
  
    <logfile>
      format %(message)s
      path /home/jim/p/zc.zservertracelog/dev/trace.log
    </logfile>
  
  </logger>

The analysis script, tracereport, can be used to analyze the trace log. I recommend the html output option.

Trace log records

• 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

• Database activity

  D -1223774356 2007-04-27T20:16:55.890371 42 0 x 2 1

  The data includes objects loaded and saved for each database except databases for which there was no activity. Note that it’s common for the main database to be unnamed, and the data often starts with objects loaded and saved for the main database.

  In the example above, 42 objects were loaded from the unnamed database. Two objects were loaded from and one saved to the database named ‘x’.

  If requests are retried due to conflict errors, then there will be multiple ‘D’ records.

• 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

Changes

2.0.0 (2019-02-26)

• Fix logic bug in seconds_difference() that could introduce error up to nearly a whole second for any particular event.

• Limit number precision in HTML reports to 3 decimal digits.

• Drop Python 2.6 support.

• Add Python 3.4 through 3.7 support.

1.4.0 (2015-05-06)

• tracereport can be limited to a date range with –date=YYYY-MM-DD..YYYY-MM-DD

1.3.2 (2012-03-20)

• Slight refactoring to allow alternative tracelog implementations.

1.3.1 (2012-03-20)

• Fix KeyError: ‘ZODB.interfaces.IConnection’ on requests that do not have a ZODB connection in annotations (e.g. GET /++etc++process).

1.3.0 (2010-04-08)

• Added ‘D’ records providing database transfer counts. This is somewhat experimental. The tracereport script ignores D records.

1.2.1 (2010-01-27)

• fix reST headings so PyPI page renders properly

• add a warning about the strange logger name

1.2.0 (2009-08-31)

• tracereport improvements: - fix parsing bugs. - add basic tests. - report time with microsecond resolution.

1.1.5 (2009-04-01)

• new key for user name in environ (refactoring in zope.app.wsgi)

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.