[Checkins] SVN: zc.zservertracelog/trunk/ merge tracereport fixes.
Alex Smith
alex at zope.com
Mon Aug 31 14:32:00 EDT 2009
Log message for revision 103417:
merge tracereport fixes.
svn merge -r 103242:HEAD svn+ssh://svn.zope.org/repos/main/zc.zservertracelog/branches/asmith-tracereport-fixes .
Changed:
U zc.zservertracelog/trunk/CHANGES.txt
A zc.zservertracelog/trunk/src/zc/zservertracelog/samples/
U zc.zservertracelog/trunk/src/zc/zservertracelog/tests.py
U zc.zservertracelog/trunk/src/zc/zservertracelog/tracereport.py
A zc.zservertracelog/trunk/src/zc/zservertracelog/tracereport.txt
-=-
Modified: zc.zservertracelog/trunk/CHANGES.txt
===================================================================
--- zc.zservertracelog/trunk/CHANGES.txt 2009-08-31 17:26:31 UTC (rev 103416)
+++ zc.zservertracelog/trunk/CHANGES.txt 2009-08-31 18:31:59 UTC (rev 103417)
@@ -2,6 +2,15 @@
Changes
=========
+unreleased
+----------
+
+- tracereport improvements:
+ - fix parsing bugs.
+ - add basic tests.
+ - report time with microsecond resolution.
+
+
1.1.5 (2009-04-01)
------------------
Modified: zc.zservertracelog/trunk/src/zc/zservertracelog/tests.py
===================================================================
--- zc.zservertracelog/trunk/src/zc/zservertracelog/tests.py 2009-08-31 17:26:31 UTC (rev 103416)
+++ zc.zservertracelog/trunk/src/zc/zservertracelog/tests.py 2009-08-31 18:31:59 UTC (rev 103417)
@@ -17,10 +17,12 @@
__docformat__ = "reStructuredText"
from zope.testing import doctest
+import os
import re
import unittest
import zope.testing.renormalizing
+here = os.path.dirname(os.path.abspath(__file__))
checker = zope.testing.renormalizing.RENormalizing([
# normalize the channel id and iso8601 timestamp
@@ -28,7 +30,6 @@
'23418928 2008-08-26 10:55:00.000000'),
])
-
_null_app = lambda environ, start_response: None
@@ -46,8 +47,12 @@
test.globs['FauxApplication'] = FauxApplication
+def analysis_setUp(test):
+ test.globs['sample_log'] = here + '/samples/trace.log'
+
+
def test_suite():
- return unittest.TestSuite([
+ tests = [
doctest.DocFileTest(
'README.txt',
optionflags=(
@@ -57,4 +62,10 @@
checker=checker,
setUp=setUp,
),
- ])
+ doctest.DocFileTest(
+ 'tracereport.txt',
+ checker=checker,
+ setUp=analysis_setUp),
+ ]
+
+ return unittest.TestSuite(tests)
Modified: zc.zservertracelog/trunk/src/zc/zservertracelog/tracereport.py
===================================================================
--- zc.zservertracelog/trunk/src/zc/zservertracelog/tracereport.py 2009-08-31 17:26:31 UTC (rev 103416)
+++ zc.zservertracelog/trunk/src/zc/zservertracelog/tracereport.py 2009-08-31 18:31:59 UTC (rev 103417)
@@ -14,10 +14,13 @@
##############################################################################
"""Yet another trace log analysis tool
"""
+import datetime
+import optparse
+import sys
+import time
-import datetime, optparse, sys
-class Request:
+class Request(object):
output_bytes = '-'
@@ -47,14 +50,15 @@
@property
def app_seconds(self):
- return (self.app_time - self.start_app_time).seconds
+ return seconds_difference(self.app_time, self.start_app_time)
@property
def total_seconds(self):
- return (self.end - self.start).seconds
+ return seconds_difference(self.end, self.start)
-class Times:
+class Times(object):
+
tid = 1l
def __init__(self):
@@ -93,17 +97,19 @@
n = len(times)
m = self.median
- return "%9.1f %5d %6.0f %6.2f %6.2f %6.0f %5d" % (
+ return "%9.1f %5d %6.2f %6.2f %6.2f %6.2f %5d" % (
self.impact, n, times[0], m, self.mean, times[-1], self.hangs)
def html(self):
times = self.times
if not times:
- print td('', 0, '', '', '', '', self.hangs)
+ impact = '<a name="u%s"> </a>' % self.tid
+ print td(
+ impact, 0, ' ', ' ', ' ', ' ', self.hangs)
else:
+ impact = '<a name="u%s">%s</a>' % (self.tid, self.impact)
n = len(times)
m = self.median
- impact = '<a name="u%s">%s' % (self.tid, self.impact)
print td(impact, n, times[0], m, self.mean, times[-1],
self.hangs)
@@ -113,17 +119,35 @@
result.hangs = self.hangs + other.hangs
return result
-def parsedt(s):
- date, time = s.split(' ')
- h_m_s, ms = time.split('.')
- return datetime.datetime(*(
- map(int, date.split('-'))
- +
- map(int, h_m_s.split(':'))
- +
- [int(ms)]
- ))
+def seconds_difference(dt1, dt2):
+ delta = dt1 - dt2
+ micros = float('0.' + str(delta.microseconds))
+ return delta.seconds + micros
+
+
+def parse_line(line):
+ parts = line.split(' ', 4)
+ code, rid, rdate, rtime = parts[:4]
+ if len(parts) > 4:
+ msg = parts[4]
+ else:
+ msg = ''
+ return (code, rid, rdate + ' ' + rtime, msg)
+
+
+def parse_datetime(s):
+ # XXX this chokes on tracelogs with the 'T' time separator.
+ date, t = s.split(' ')
+ try:
+ h_m_s, ms = t.split('.')
+ except ValueError:
+ h_m_s = t.strip()
+ ms = '0'
+ args = [int(arg) for arg in (date.split('-') + h_m_s.split(':') + [ms])]
+ return datetime.datetime(*args)
+
+
def main(args=None):
if args is None:
args = sys.argv[1:]
@@ -171,9 +195,10 @@
file = open(file)
for record in file:
- record = record.split()
- typ, rid, dt, min = record[:4]
- dt = parsedt(' '.join([dt,min]))
+ typ, rid, strtime, msg = parse_line(record)
+ min = strtime.split('.')[0]
+ min = min[:-3]
+ dt = parse_datetime(strtime)
if dt == restart:
continue
while dt > restart:
@@ -215,10 +240,14 @@
input -= 1
input += 1
- request = Request(dt, *record[3:5])
+ method, url = msg.split(' ', 1)
+ request = Request(dt, method, url.strip())
if remove_prefix and request.url.startswith(remove_prefix):
request.url = request.url[len(remove_prefix):]
requests[rid] = request
+ times = urls.get(request.url)
+ if times is None:
+ times = urls[request.url] = Times()
elif typ == 'I':
if rid in requests:
input -= 1
@@ -233,7 +262,12 @@
if rid in requests:
apps -= 1
output += 1
- requests[rid].A(dt, *record[3:5])
+ try:
+ response_code, bytes_len = msg.split()
+ except ValueError:
+ response_code = '500'
+ bytes_len = len(msg)
+ requests[rid].A(dt, response_code, bytes_len)
elif typ == 'E':
if rid in requests:
output -= 1
@@ -242,10 +276,7 @@
spr += request.total_seconds
spa += request.app_seconds
n += 1
- url = "%s -> %s" % (request.url, request.response)
- times = urls.get(url)
- if times is None:
- times = urls[url] = Times()
+ times = urls[request.url]
times.finished(request)
elif typ in 'SX':
@@ -261,6 +292,7 @@
else:
print 'WTF', record
+ record_hung(urls, requests)
print_app_requests(requests, dt,
options.old_requests,
options.app_requests,
@@ -344,7 +376,7 @@
print '</table>'
def output_minute_text(lmin, requests, input, wait, apps, output, n, spr, spa):
- print lmin.replace('T', ' '), " %5d I=%3d W=%3d A=%3d O=%5d " % (
+ print lmin, "%5d I=%3d W=%3d A=%3d O=%4d" % (
len(requests), input, wait, apps, output),
if n:
print "N=%4d %10.2f %10.2f" % (n, spr/n, spa/n)
@@ -363,9 +395,11 @@
else:
print '<tr>'
apps = '<font size="+2"><strong>%s</strong></font>' % apps
- print td(lmin.replace('T', ' '), len(requests), input, wait, apps, output)
+ print td(lmin, len(requests), input, wait, apps, output)
if n:
print td(n, "%10.2f" % (spr/n), "%10.2f" % (spa/n))
+ else:
+ print td(n, ' ', ' ')
print '</tr>'
def find_restarts(event_log):
@@ -382,10 +416,10 @@
times = urls[request.url] = Times()
times.hung()
-def print_app_requests_text(requests, dt, min_seconds, max_requests, urls,
+def print_app_requests_text(requests, dt, min_seconds, max_requests, allurls,
label=''):
requests = [
- ((dt-request.start).seconds, request)
+ (seconds_difference(dt, request.start), request)
for request in requests.values()
if request.state == 'app'
]
@@ -431,7 +465,7 @@
print label
label = ''
if not printed:
- minutes_footer_html()
+ print '</table>'
print '<table border="1">'
print '<tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>'
printed = True
@@ -448,8 +482,7 @@
print '</table>'
minutes_header_html()
-parser = optparse.OptionParser("""
-Usage: %prog [options] trace_log_file
+parser = optparse.OptionParser("""%prog [options] trace_log_file
Output trace log data showing:
Copied: zc.zservertracelog/trunk/src/zc/zservertracelog/tracereport.txt (from rev 103416, zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.txt)
===================================================================
--- zc.zservertracelog/trunk/src/zc/zservertracelog/tracereport.txt (rev 0)
+++ zc.zservertracelog/trunk/src/zc/zservertracelog/tracereport.txt 2009-08-31 18:31:59 UTC (rev 103417)
@@ -0,0 +1,618 @@
+===================
+Analyzing Tracelogs
+===================
+
+`tracereport.py` provides a basic means to analyze a tracelog and generate a
+report.
+
+ >>> import zc.zservertracelog.tracereport
+
+The '--help' option displays the following usage information:
+
+ >>> try:
+ ... zc.zservertracelog.tracereport.main(['--help'])
+ ... except SystemExit:
+ ... pass
+ usage: test [options] trace_log_file
+ <BLANKLINE>
+ Output trace log data showing:
+ <BLANKLINE>
+ - number of active requests,
+ - number of input requests (requests gathering input),
+ - number of application requests,
+ - number of output requests,
+ - number of requests completed in the minute shown,
+ - mean seconds per request and
+ - mean application seconds per request.
+ <BLANKLINE>
+ Note that we don't seem to be logging when a connection to the client
+ is broken, so the number of active requests, and especially the number
+ of outputing requests tends to grow over time. This is spurious.
+ <BLANKLINE>
+ Also, note that, unfortunately, application requests include requests
+ that are running in application threads and requests waiting to get an
+ application thread.
+ <BLANKLINE>
+ When application threads get above the app request threshold, then we
+ show the requests that have been waiting the longest.
+ <BLANKLINE>
+ <BLANKLINE>
+ <BLANKLINE>
+ options:
+ -h, --help show this help message and exit
+ -a APPS, --app-request-threshold=APPS
+ Number of pending application requests at which
+ detailed request information if printed.
+ -r APP_REQUESTS, --app-requests=APP_REQUESTS
+ How many requests to show when the maximum number of
+ pending apps is exceeded.
+ -o OLD_REQUESTS, --old-requests=OLD_REQUESTS
+ Number of seconds beyond which a request is
+ considered old.
+ -e EVENT_LOG, --event-log=EVENT_LOG
+ The name of an event log that goes with the trace
+ log. This is used to determine when the server is
+ restarted, so that the running trace data structures
+ can be reinitialized.
+ --html Generate HTML output.
+ --remove-prefix=REMOVE_PREFIX
+ A prefex to be removed from URLS.
+ --summary-only Only output summary lines.
+ --summary-lines=SUMMARY_LINES
+ The number of summary lines to show
+
+Here, we display the summarized report for a sample trace log.
+
+ >>> zc.zservertracelog.tracereport.main(
+ ... ['--summary-only', '--app-request-threshold', '0', sample_log])
+ <BLANKLINE>
+ URL statistics:
+ Impact count min median mean max hangs
+ ========= ===== ====== ====== ====== ====== =====
+ 62.4 1 62.42 62.42 62.42 62.42 0 /constellations/andromeda.html
+ 61.5 1 61.50 61.50 61.50 61.50 0 /stars/alpha-centauri.html
+ 60.7 2 0.34 30.34 30.34 60.34 0 /space-travel/plans/supplies.txt
+ 60.3 2 0.13 30.13 30.13 60.13 0 /favicon.png
+ 9.7 1 9.69 9.69 9.69 9.69 0 /planets/saturn.html
+ 8.3 1 8.30 8.30 8.30 8.30 0 /moons/io.html
+ 7.3 1 7.34 7.34 7.34 7.34 0 /planets/jupiter.html
+ 1.0 3 0.31 0.35 0.35 0.38 0 /space-travel/plans/signals.html
+ 0.9 1 0.88 0.88 0.88 0.88 0 /stories/aliens-posing-as-humans.html
+ 0.8 2 0.35 0.39 0.39 0.42 0 /space-travel/plans/launchpad.html
+ 0.7 1 0.36 0.36 0.36 0.36 1 /space-travel/plans/orbit.html
+ 0.7 2 0.34 0.36 0.36 0.38 0 /space-travel/plans/space-logs.txt
+ 0.7 2 0.35 0.35 0.35 0.35 0 /space-travel/plans/moon-base.jpg
+ 0.6 1 0.64 0.64 0.64 0.64 0 /columns/t-jansen
+ 0.5 3 0.15 0.16 0.16 0.18 0 /space-travelers/famous/kirk.jpg
+ 0.4 1 0.40 0.40 0.40 0.40 0 /space-travel/plans/moon-buggy.jpg
+ 0.4 1 0.38 0.38 0.38 0.38 0 /space-travel/plans/space-diary.txt
+ 0.4 2 0.18 0.19 0.19 0.19 0 /faqs/how-to-recognize-lazer-fire.html
+ 0.4 1 0.35 0.35 0.35 0.35 0 /js/photo.js
+ 0.4 1 0.35 0.35 0.35 0.35 0 /space-travel/plans/visor.jpg
+ 0.4 1 0.35 0.35 0.35 0.35 0 /space-travel/plans/lunar-cycles.html
+ 0.4 1 0.35 0.35 0.35 0.35 0 /faqs/how-to-charge-lazers.html
+ 0.3 1 0.33 0.33 0.33 0.33 0 /space-travel/plans/cryostasis.txt
+ 0.3 1 0.32 0.32 0.32 0.32 0 /space-travel/plans/space-suit.jpg
+ 0.3 1 0.32 0.32 0.32 0.32 0 /space-travel/ships/tardis.html
+ 0.3 1 0.25 0.25 0.25 0.25 0 /approve-photo
+ 0.2 1 0.18 0.18 0.18 0.18 0 /ufo-sightings/report
+ 0.2 1 0.16 0.16 0.16 0.16 0 /space-travelers/famous/spock.jpg
+ 0.2 1 0.16 0.16 0.16 0.16 0 /login
+ 0.1 1 0.14 0.14 0.14 0.14 0 /space-travel/ships/soyuz.html
+ 0 1 /submit-photo
+
+This can also be displayed as HTML.
+
+ >>> zc.zservertracelog.tracereport.main(
+ ... ['--summary-only', '--html', '--app-request-threshold', '0', sample_log])
+ <html title="trace log statistics"><body>
+ <BLANKLINE>
+ URL statistics:
+ <table border="1">
+ <tr><th>Impact</th><th>count</th><th>min</th>
+ <th>median</th><th>mean</th><th>max</th><th>hangs</th></tr>
+ <tr>
+ <td><a name="u37">62.41844</a></td><td>1</td><td>62.41844</td><td>62.41844</td><td>62.41844</td><td>62.41844</td><td>0</td>
+ <td>/constellations/andromeda.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u53">61.502412</a></td><td>1</td><td>61.502412</td><td>61.502412</td><td>61.502412</td><td>61.502412</td><td>0</td>
+ <td>/stars/alpha-centauri.html</td>
+ </tr>
+ <tr>
+ <td><a name="u34">60.6803</a></td><td>2</td><td>0.3372</td><td>30.34015</td><td>30.34015</td><td>60.3431</td><td>0</td>
+ <td>/space-travel/plans/supplies.txt</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u44">60.267171</a></td><td>2</td><td>0.132899</td><td>30.1335855</td><td>30.1335855</td><td>60.134272</td><td>0</td>
+ <td>/favicon.png</td>
+ </tr>
+ <tr>
+ <td><a name="u48">9.693661</a></td><td>1</td><td>9.693661</td><td>9.693661</td><td>9.693661</td><td>9.693661</td><td>0</td>
+ <td>/planets/saturn.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u51">8.29953</a></td><td>1</td><td>8.29953</td><td>8.29953</td><td>8.29953</td><td>8.29953</td><td>0</td>
+ <td>/moons/io.html</td>
+ </tr>
+ <tr>
+ <td><a name="u55">7.339574</a></td><td>1</td><td>7.339574</td><td>7.339574</td><td>7.339574</td><td>7.339574</td><td>0</td>
+ <td>/planets/jupiter.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u56">1.0394</a></td><td>3</td><td>0.3092</td><td>0.3526</td><td>0.346466666667</td><td>0.3776</td><td>0</td>
+ <td>/space-travel/plans/signals.html</td>
+ </tr>
+ <tr>
+ <td><a name="u60">0.879732</a></td><td>1</td><td>0.879732</td><td>0.879732</td><td>0.879732</td><td>0.879732</td><td>0</td>
+ <td>/stories/aliens-posing-as-humans.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u36">0.7755</a></td><td>2</td><td>0.3523</td><td>0.38775</td><td>0.38775</td><td>0.4232</td><td>0</td>
+ <td>/space-travel/plans/launchpad.html</td>
+ </tr>
+ <tr>
+ <td><a name="u62">0.729</a></td><td>1</td><td>0.3645</td><td>0.3645</td><td>0.3645</td><td>0.3645</td><td>1</td>
+ <td>/space-travel/plans/orbit.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u38">0.7221</a></td><td>2</td><td>0.3385</td><td>0.36105</td><td>0.36105</td><td>0.3836</td><td>0</td>
+ <td>/space-travel/plans/space-logs.txt</td>
+ </tr>
+ <tr>
+ <td><a name="u35">0.6988</a></td><td>2</td><td>0.3474</td><td>0.3494</td><td>0.3494</td><td>0.3514</td><td>0</td>
+ <td>/space-travel/plans/moon-base.jpg</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u33">0.63826</a></td><td>1</td><td>0.63826</td><td>0.63826</td><td>0.63826</td><td>0.63826</td><td>0</td>
+ <td>/columns/t-jansen</td>
+ </tr>
+ <tr>
+ <td><a name="u45">0.49124</a></td><td>3</td><td>0.1529</td><td>0.16141</td><td>0.163746666667</td><td>0.17693</td><td>0</td>
+ <td>/space-travelers/famous/kirk.jpg</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u46">0.3967</a></td><td>1</td><td>0.3967</td><td>0.3967</td><td>0.3967</td><td>0.3967</td><td>0</td>
+ <td>/space-travel/plans/moon-buggy.jpg</td>
+ </tr>
+ <tr>
+ <td><a name="u49">0.3794</a></td><td>1</td><td>0.3794</td><td>0.3794</td><td>0.3794</td><td>0.3794</td><td>0</td>
+ <td>/space-travel/plans/space-diary.txt</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u41">0.374609</a></td><td>2</td><td>0.184486</td><td>0.1873045</td><td>0.1873045</td><td>0.190123</td><td>0</td>
+ <td>/faqs/how-to-recognize-lazer-fire.html</td>
+ </tr>
+ <tr>
+ <td><a name="u58">0.3542</a></td><td>1</td><td>0.3542</td><td>0.3542</td><td>0.3542</td><td>0.3542</td><td>0</td>
+ <td>/js/photo.js</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u63">0.354</a></td><td>1</td><td>0.354</td><td>0.354</td><td>0.354</td><td>0.354</td><td>0</td>
+ <td>/space-travel/plans/visor.jpg</td>
+ </tr>
+ <tr>
+ <td><a name="u52">0.3526</a></td><td>1</td><td>0.3526</td><td>0.3526</td><td>0.3526</td><td>0.3526</td><td>0</td>
+ <td>/space-travel/plans/lunar-cycles.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u54">0.350755</a></td><td>1</td><td>0.350755</td><td>0.350755</td><td>0.350755</td><td>0.350755</td><td>0</td>
+ <td>/faqs/how-to-charge-lazers.html</td>
+ </tr>
+ <tr>
+ <td><a name="u40">0.3325</a></td><td>1</td><td>0.3325</td><td>0.3325</td><td>0.3325</td><td>0.3325</td><td>0</td>
+ <td>/space-travel/plans/cryostasis.txt</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u47">0.3211</a></td><td>1</td><td>0.3211</td><td>0.3211</td><td>0.3211</td><td>0.3211</td><td>0</td>
+ <td>/space-travel/plans/space-suit.jpg</td>
+ </tr>
+ <tr>
+ <td><a name="u50">0.31994</a></td><td>1</td><td>0.31994</td><td>0.31994</td><td>0.31994</td><td>0.31994</td><td>0</td>
+ <td>/space-travel/ships/tardis.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u39">0.252708</a></td><td>1</td><td>0.252708</td><td>0.252708</td><td>0.252708</td><td>0.252708</td><td>0</td>
+ <td>/approve-photo</td>
+ </tr>
+ <tr>
+ <td><a name="u57">0.181654</a></td><td>1</td><td>0.181654</td><td>0.181654</td><td>0.181654</td><td>0.181654</td><td>0</td>
+ <td>/ufo-sightings/report</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u59">0.15727</a></td><td>1</td><td>0.15727</td><td>0.15727</td><td>0.15727</td><td>0.15727</td><td>0</td>
+ <td>/space-travelers/famous/spock.jpg</td>
+ </tr>
+ <tr>
+ <td><a name="u43">0.15669</a></td><td>1</td><td>0.15669</td><td>0.15669</td><td>0.15669</td><td>0.15669</td><td>0</td>
+ <td>/login</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u61">0.137797</a></td><td>1</td><td>0.137797</td><td>0.137797</td><td>0.137797</td><td>0.137797</td><td>0</td>
+ <td>/space-travel/ships/soyuz.html</td>
+ </tr>
+ <tr>
+ <td><a name="u42"> </a></td><td>0</td><td> </td><td> </td><td> </td><td> </td><td>1</td>
+ <td>/submit-photo</td>
+ </tr>
+ </table>
+ </body></html>
+
+The full report shows the request activity per minute.
+
+ >>> zc.zservertracelog.tracereport.main(
+ ... ['--app-request-threshold', '0', sample_log])
+ <BLANKLINE>
+ minute req input wait app output
+ ================ ===== ===== ===== ===== ======
+ 2009-07-30 15:47 1 I= 0 W= 0 A= 1 O= 0 N= 1 0.64 0.64
+ 60.4106 /space-travel/plans/supplies.txt
+ 2009-07-30 15:48 2 I= 0 W= 1 A= 1 O= 0 N= 3 20.43 20.35
+ 60.791825 /constellations/andromeda.html
+ 2009-07-30 15:49 0 I= 0 W= 0 A= 0 O= 0 N= 4 31.81 15.85
+ 2009-07-30 15:50 2 I= 0 W= 0 A= 2 O= 0 N= 2 0.34 0.17
+ 60.62335 /submit-photo
+ 60.209388 /favicon.png
+ 2009-07-30 15:51 3 I= 0 W= 1 A= 1 O= 1 N= 5 12.31 12.25
+ 121.301024 /submit-photo
+ 2009-07-30 15:52 3 I= 0 W= 1 A= 2 O= 0 N= 8 20.65 2.52
+ 200.494494 /submit-photo
+ 68.9801 /stars/alpha-centauri.html
+ 2009-07-30 15:53 3 I= 0 W= 2 A= 1 O= 0 N= 11 14.53 6.53
+ 270.622261 /submit-photo
+ Left over:
+ 271.214443 /submit-photo
+ <BLANKLINE>
+ <BLANKLINE>
+ URL statistics:
+ Impact count min median mean max hangs
+ ========= ===== ====== ====== ====== ====== =====
+ 62.4 1 62.42 62.42 62.42 62.42 0 /constellations/andromeda.html
+ 61.5 1 61.50 61.50 61.50 61.50 0 /stars/alpha-centauri.html
+ 60.7 2 0.34 30.34 30.34 60.34 0 /space-travel/plans/supplies.txt
+ 60.3 2 0.13 30.13 30.13 60.13 0 /favicon.png
+ 9.7 1 9.69 9.69 9.69 9.69 0 /planets/saturn.html
+ 8.3 1 8.30 8.30 8.30 8.30 0 /moons/io.html
+ 7.3 1 7.34 7.34 7.34 7.34 0 /planets/jupiter.html
+ 1.0 3 0.31 0.35 0.35 0.38 0 /space-travel/plans/signals.html
+ 0.9 1 0.88 0.88 0.88 0.88 0 /stories/aliens-posing-as-humans.html
+ 0.8 2 0.35 0.39 0.39 0.42 0 /space-travel/plans/launchpad.html
+ 0.7 1 0.36 0.36 0.36 0.36 1 /space-travel/plans/orbit.html
+ 0.7 2 0.34 0.36 0.36 0.38 0 /space-travel/plans/space-logs.txt
+ 0.7 2 0.35 0.35 0.35 0.35 0 /space-travel/plans/moon-base.jpg
+ 0.6 1 0.64 0.64 0.64 0.64 0 /columns/t-jansen
+ 0.5 3 0.15 0.16 0.16 0.18 0 /space-travelers/famous/kirk.jpg
+ 0.4 1 0.40 0.40 0.40 0.40 0 /space-travel/plans/moon-buggy.jpg
+ 0.4 1 0.38 0.38 0.38 0.38 0 /space-travel/plans/space-diary.txt
+ 0.4 2 0.18 0.19 0.19 0.19 0 /faqs/how-to-recognize-lazer-fire.html
+ 0.4 1 0.35 0.35 0.35 0.35 0 /js/photo.js
+ 0.4 1 0.35 0.35 0.35 0.35 0 /space-travel/plans/visor.jpg
+ 0.4 1 0.35 0.35 0.35 0.35 0 /space-travel/plans/lunar-cycles.html
+ 0.4 1 0.35 0.35 0.35 0.35 0 /faqs/how-to-charge-lazers.html
+ 0.3 1 0.33 0.33 0.33 0.33 0 /space-travel/plans/cryostasis.txt
+ 0.3 1 0.32 0.32 0.32 0.32 0 /space-travel/plans/space-suit.jpg
+ 0.3 1 0.32 0.32 0.32 0.32 0 /space-travel/ships/tardis.html
+ 0.3 1 0.25 0.25 0.25 0.25 0 /approve-photo
+ 0.2 1 0.18 0.18 0.18 0.18 0 /ufo-sightings/report
+ 0.2 1 0.16 0.16 0.16 0.16 0 /space-travelers/famous/spock.jpg
+ 0.2 1 0.16 0.16 0.16 0.16 0 /login
+ 0.1 1 0.14 0.14 0.14 0.14 0 /space-travel/ships/soyuz.html
+ 0 1 /submit-photo
+
+Again, this report is also available in HTML form.
+
+ >>> zc.zservertracelog.tracereport.main(
+ ... ['--html', '--app-request-threshold', '0', sample_log])
+ <html title="trace log statistics"><body>
+ <table border="2">
+ <tr>
+ <th>Minute</th>
+ <th>Requests</th>
+ <th>Requests inputing</th>
+ <th>Requests waiting</th>
+ <th>Requests executing</th>
+ <th>Requests outputing</th>
+ <th>Requests completed</th>
+ <th>Mean Seconds Per Request Total</th>
+ <th>Mean Seconds Per Request in App</th>
+ </tr>
+ <tr style="background: lightgrey">
+ <td>2009-07-30 15:47</td><td>1</td><td>0</td><td>0</td><td><font size="+2"><strong>1</strong></font></td><td>0</td>
+ <td>1</td><td> 0.64</td><td> 0.64</td>
+ </tr>
+ </table>
+ <table border="1">
+ <tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>
+ <tr>
+ <td>60</td><td></td><td><a href="#u96">/space-travel/plans/supplies.txt</a></td><td>app</td>
+ </tr>
+ </table>
+ <table border="2">
+ <tr>
+ <th>Minute</th>
+ <th>Requests</th>
+ <th>Requests inputing</th>
+ <th>Requests waiting</th>
+ <th>Requests executing</th>
+ <th>Requests outputing</th>
+ <th>Requests completed</th>
+ <th>Mean Seconds Per Request Total</th>
+ <th>Mean Seconds Per Request in App</th>
+ </tr>
+ <tr>
+ <td>2009-07-30 15:48</td><td>2</td><td>0</td><td>1</td><td><font size="+2"><strong>1</strong></font></td><td>0</td>
+ <td>3</td><td> 20.43</td><td> 20.35</td>
+ </tr>
+ </table>
+ <table border="1">
+ <tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>
+ <tr>
+ <td>60</td><td></td><td><a href="#u99">/constellations/andromeda.html</a></td><td>app</td>
+ </tr>
+ </table>
+ <table border="2">
+ <tr>
+ <th>Minute</th>
+ <th>Requests</th>
+ <th>Requests inputing</th>
+ <th>Requests waiting</th>
+ <th>Requests executing</th>
+ <th>Requests outputing</th>
+ <th>Requests completed</th>
+ <th>Mean Seconds Per Request Total</th>
+ <th>Mean Seconds Per Request in App</th>
+ </tr>
+ <tr style="background: lightgrey">
+ <td>2009-07-30 15:49</td><td>0</td><td>0</td><td>0</td><td><font size="+2"><strong>0</strong></font></td><td>0</td>
+ <td>4</td><td> 31.81</td><td> 15.85</td>
+ </tr>
+ <tr>
+ <td>2009-07-30 15:50</td><td>2</td><td>0</td><td>0</td><td><font size="+2"><strong>2</strong></font></td><td>0</td>
+ <td>2</td><td> 0.34</td><td> 0.17</td>
+ </tr>
+ </table>
+ <table border="1">
+ <tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>
+ <tr>
+ <td>60</td><td></td><td><a href="#u104">/submit-photo</a></td><td>app</td>
+ </tr>
+ <tr>
+ <td>60</td><td></td><td><a href="#u106">/favicon.png</a></td><td>app</td>
+ </tr>
+ </table>
+ <table border="2">
+ <tr>
+ <th>Minute</th>
+ <th>Requests</th>
+ <th>Requests inputing</th>
+ <th>Requests waiting</th>
+ <th>Requests executing</th>
+ <th>Requests outputing</th>
+ <th>Requests completed</th>
+ <th>Mean Seconds Per Request Total</th>
+ <th>Mean Seconds Per Request in App</th>
+ </tr>
+ <tr style="background: lightgrey">
+ <td>2009-07-30 15:51</td><td>3</td><td>0</td><td>1</td><td><font size="+2"><strong>1</strong></font></td><td>1</td>
+ <td>5</td><td> 12.31</td><td> 12.25</td>
+ </tr>
+ </table>
+ <table border="1">
+ <tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>
+ <tr>
+ <td>121</td><td></td><td><a href="#u104">/submit-photo</a></td><td>app</td>
+ </tr>
+ </table>
+ <table border="2">
+ <tr>
+ <th>Minute</th>
+ <th>Requests</th>
+ <th>Requests inputing</th>
+ <th>Requests waiting</th>
+ <th>Requests executing</th>
+ <th>Requests outputing</th>
+ <th>Requests completed</th>
+ <th>Mean Seconds Per Request Total</th>
+ <th>Mean Seconds Per Request in App</th>
+ </tr>
+ <tr>
+ <td>2009-07-30 15:52</td><td>3</td><td>0</td><td>1</td><td><font size="+2"><strong>2</strong></font></td><td>0</td>
+ <td>8</td><td> 20.65</td><td> 2.52</td>
+ </tr>
+ </table>
+ <table border="1">
+ <tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>
+ <tr>
+ <td>200</td><td></td><td><a href="#u104">/submit-photo</a></td><td>app</td>
+ </tr>
+ <tr>
+ <td>68</td><td></td><td><a href="#u115">/stars/alpha-centauri.html</a></td><td>app</td>
+ </tr>
+ </table>
+ <table border="2">
+ <tr>
+ <th>Minute</th>
+ <th>Requests</th>
+ <th>Requests inputing</th>
+ <th>Requests waiting</th>
+ <th>Requests executing</th>
+ <th>Requests outputing</th>
+ <th>Requests completed</th>
+ <th>Mean Seconds Per Request Total</th>
+ <th>Mean Seconds Per Request in App</th>
+ </tr>
+ <tr style="background: lightgrey">
+ <td>2009-07-30 15:53</td><td>3</td><td>0</td><td>2</td><td><font size="+2"><strong>1</strong></font></td><td>0</td>
+ <td>11</td><td> 14.53</td><td> 6.53</td>
+ </tr>
+ </table>
+ <table border="1">
+ <tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>
+ <tr>
+ <td>270</td><td></td><td><a href="#u104">/submit-photo</a></td><td>app</td>
+ </tr>
+ </table>
+ <table border="2">
+ <tr>
+ <th>Minute</th>
+ <th>Requests</th>
+ <th>Requests inputing</th>
+ <th>Requests waiting</th>
+ <th>Requests executing</th>
+ <th>Requests outputing</th>
+ <th>Requests completed</th>
+ <th>Mean Seconds Per Request Total</th>
+ <th>Mean Seconds Per Request in App</th>
+ </tr>
+ Left over:
+ </table>
+ <table border="1">
+ <tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>
+ <tr>
+ <td>271</td><td></td><td><a href="#u104">/submit-photo</a></td><td>app</td>
+ </tr>
+ </table>
+ <table border="2">
+ <tr>
+ <th>Minute</th>
+ <th>Requests</th>
+ <th>Requests inputing</th>
+ <th>Requests waiting</th>
+ <th>Requests executing</th>
+ <th>Requests outputing</th>
+ <th>Requests completed</th>
+ <th>Mean Seconds Per Request Total</th>
+ <th>Mean Seconds Per Request in App</th>
+ </tr>
+ </table>
+ <BLANKLINE>
+ URL statistics:
+ <table border="1">
+ <tr><th>Impact</th><th>count</th><th>min</th>
+ <th>median</th><th>mean</th><th>max</th><th>hangs</th></tr>
+ <tr>
+ <td><a name="u99">62.41844</a></td><td>1</td><td>62.41844</td><td>62.41844</td><td>62.41844</td><td>62.41844</td><td>0</td>
+ <td>/constellations/andromeda.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u115">61.502412</a></td><td>1</td><td>61.502412</td><td>61.502412</td><td>61.502412</td><td>61.502412</td><td>0</td>
+ <td>/stars/alpha-centauri.html</td>
+ </tr>
+ <tr>
+ <td><a name="u96">60.6803</a></td><td>2</td><td>0.3372</td><td>30.34015</td><td>30.34015</td><td>60.3431</td><td>0</td>
+ <td>/space-travel/plans/supplies.txt</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u106">60.267171</a></td><td>2</td><td>0.132899</td><td>30.1335855</td><td>30.1335855</td><td>60.134272</td><td>0</td>
+ <td>/favicon.png</td>
+ </tr>
+ <tr>
+ <td><a name="u110">9.693661</a></td><td>1</td><td>9.693661</td><td>9.693661</td><td>9.693661</td><td>9.693661</td><td>0</td>
+ <td>/planets/saturn.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u113">8.29953</a></td><td>1</td><td>8.29953</td><td>8.29953</td><td>8.29953</td><td>8.29953</td><td>0</td>
+ <td>/moons/io.html</td>
+ </tr>
+ <tr>
+ <td><a name="u117">7.339574</a></td><td>1</td><td>7.339574</td><td>7.339574</td><td>7.339574</td><td>7.339574</td><td>0</td>
+ <td>/planets/jupiter.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u118">1.0394</a></td><td>3</td><td>0.3092</td><td>0.3526</td><td>0.346466666667</td><td>0.3776</td><td>0</td>
+ <td>/space-travel/plans/signals.html</td>
+ </tr>
+ <tr>
+ <td><a name="u122">0.879732</a></td><td>1</td><td>0.879732</td><td>0.879732</td><td>0.879732</td><td>0.879732</td><td>0</td>
+ <td>/stories/aliens-posing-as-humans.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u98">0.7755</a></td><td>2</td><td>0.3523</td><td>0.38775</td><td>0.38775</td><td>0.4232</td><td>0</td>
+ <td>/space-travel/plans/launchpad.html</td>
+ </tr>
+ <tr>
+ <td><a name="u124">0.729</a></td><td>1</td><td>0.3645</td><td>0.3645</td><td>0.3645</td><td>0.3645</td><td>1</td>
+ <td>/space-travel/plans/orbit.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u100">0.7221</a></td><td>2</td><td>0.3385</td><td>0.36105</td><td>0.36105</td><td>0.3836</td><td>0</td>
+ <td>/space-travel/plans/space-logs.txt</td>
+ </tr>
+ <tr>
+ <td><a name="u97">0.6988</a></td><td>2</td><td>0.3474</td><td>0.3494</td><td>0.3494</td><td>0.3514</td><td>0</td>
+ <td>/space-travel/plans/moon-base.jpg</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u95">0.63826</a></td><td>1</td><td>0.63826</td><td>0.63826</td><td>0.63826</td><td>0.63826</td><td>0</td>
+ <td>/columns/t-jansen</td>
+ </tr>
+ <tr>
+ <td><a name="u107">0.49124</a></td><td>3</td><td>0.1529</td><td>0.16141</td><td>0.163746666667</td><td>0.17693</td><td>0</td>
+ <td>/space-travelers/famous/kirk.jpg</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u108">0.3967</a></td><td>1</td><td>0.3967</td><td>0.3967</td><td>0.3967</td><td>0.3967</td><td>0</td>
+ <td>/space-travel/plans/moon-buggy.jpg</td>
+ </tr>
+ <tr>
+ <td><a name="u111">0.3794</a></td><td>1</td><td>0.3794</td><td>0.3794</td><td>0.3794</td><td>0.3794</td><td>0</td>
+ <td>/space-travel/plans/space-diary.txt</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u103">0.374609</a></td><td>2</td><td>0.184486</td><td>0.1873045</td><td>0.1873045</td><td>0.190123</td><td>0</td>
+ <td>/faqs/how-to-recognize-lazer-fire.html</td>
+ </tr>
+ <tr>
+ <td><a name="u120">0.3542</a></td><td>1</td><td>0.3542</td><td>0.3542</td><td>0.3542</td><td>0.3542</td><td>0</td>
+ <td>/js/photo.js</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u125">0.354</a></td><td>1</td><td>0.354</td><td>0.354</td><td>0.354</td><td>0.354</td><td>0</td>
+ <td>/space-travel/plans/visor.jpg</td>
+ </tr>
+ <tr>
+ <td><a name="u114">0.3526</a></td><td>1</td><td>0.3526</td><td>0.3526</td><td>0.3526</td><td>0.3526</td><td>0</td>
+ <td>/space-travel/plans/lunar-cycles.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u116">0.350755</a></td><td>1</td><td>0.350755</td><td>0.350755</td><td>0.350755</td><td>0.350755</td><td>0</td>
+ <td>/faqs/how-to-charge-lazers.html</td>
+ </tr>
+ <tr>
+ <td><a name="u102">0.3325</a></td><td>1</td><td>0.3325</td><td>0.3325</td><td>0.3325</td><td>0.3325</td><td>0</td>
+ <td>/space-travel/plans/cryostasis.txt</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u109">0.3211</a></td><td>1</td><td>0.3211</td><td>0.3211</td><td>0.3211</td><td>0.3211</td><td>0</td>
+ <td>/space-travel/plans/space-suit.jpg</td>
+ </tr>
+ <tr>
+ <td><a name="u112">0.31994</a></td><td>1</td><td>0.31994</td><td>0.31994</td><td>0.31994</td><td>0.31994</td><td>0</td>
+ <td>/space-travel/ships/tardis.html</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u101">0.252708</a></td><td>1</td><td>0.252708</td><td>0.252708</td><td>0.252708</td><td>0.252708</td><td>0</td>
+ <td>/approve-photo</td>
+ </tr>
+ <tr>
+ <td><a name="u119">0.181654</a></td><td>1</td><td>0.181654</td><td>0.181654</td><td>0.181654</td><td>0.181654</td><td>0</td>
+ <td>/ufo-sightings/report</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u121">0.15727</a></td><td>1</td><td>0.15727</td><td>0.15727</td><td>0.15727</td><td>0.15727</td><td>0</td>
+ <td>/space-travelers/famous/spock.jpg</td>
+ </tr>
+ <tr>
+ <td><a name="u105">0.15669</a></td><td>1</td><td>0.15669</td><td>0.15669</td><td>0.15669</td><td>0.15669</td><td>0</td>
+ <td>/login</td>
+ </tr>
+ <tr style="background: lightgrey;">
+ <td><a name="u123">0.137797</a></td><td>1</td><td>0.137797</td><td>0.137797</td><td>0.137797</td><td>0.137797</td><td>0</td>
+ <td>/space-travel/ships/soyuz.html</td>
+ </tr>
+ <tr>
+ <td><a name="u104"> </a></td><td>0</td><td> </td><td> </td><td> </td><td> </td><td>1</td>
+ <td>/submit-photo</td>
+ </tr>
+ </table>
+ </body></html>
More information about the checkins
mailing list