[Checkins] SVN: zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/ - fix parsing rot in `tracereport.py`.

Alex Smith alex at zope.com
Wed Aug 26 17:43:17 EDT 2009


Log message for revision 103243:
  - fix parsing rot in `tracereport.py`.
  - add basic test coverage with (much still to do).
  
  

Changed:
  A   zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/samples/
  A   zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/samples/trace.log
  U   zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tests.py
  U   zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.py
  A   zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.txt

-=-
Added: zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/samples/trace.log
===================================================================
--- zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/samples/trace.log	                        (rev 0)
+++ zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/samples/trace.log	2009-08-26 21:43:17 UTC (rev 103243)
@@ -0,0 +1,210 @@
+C 0.-1429402676 2009-07-30 15:47:18.436894
+A 0.-1429402676 2009-07-30 15:47:21.349080 302 0
+E 0.-1429402676 2009-07-30 15:47:21.349251
+B 0.-1451819092 2009-07-30 15:47:21.560343 GET /columns/t-jansen
+I 0.-1451819092 2009-07-30 15:47:21.560763 0
+C 0.-1451819092 2009-07-30 15:47:21.561006
+A 0.-1451819092 2009-07-30 15:47:22.199266 200 93638
+E 0.-1451819092 2009-07-30 15:47:22.199799
+B 0.-1444488820 2009-07-30 15:47:22.326074 GET /space-travel/plans/supplies.txt
+I 0.-1444488820 2009-07-30 15:47:22.326470 0
+C 0.-1444488820 2009-07-30 15:47:22.326749
+A 0.-1444488820 2009-07-30 15:47:22.330180 304 0
+E 0.-1444488820 2009-07-30 15:47:22.330342
+B 0.-1451819828 2009-07-30 15:47:22.461693 GET /space-travel/plans/moon-base.jpg
+I 0.-1451819828 2009-07-30 15:47:22.462072 0
+C 0.-1451819828 2009-07-30 15:47:22.462377
+A 0.-1451819828 2009-07-30 15:47:22.465851 304 0
+E 0.-1451819828 2009-07-30 15:47:22.466004
+B 0.-1451079668 2009-07-30 15:47:22.610208 GET /space-travel/plans/launchpad.html
+I 0.-1451079668 2009-07-30 15:47:22.610608 0
+C 0.-1451079668 2009-07-30 15:47:22.610858
+A 0.-1451079668 2009-07-30 15:47:22.614381 304 0
+E 0.-1451079668 2009-07-30 15:47:22.614542
+B 0.-1451822804 2009-07-30 15:47:22.727420 GET /constellations/andromeda.html
+I 0.-1451822804 2009-07-30 15:47:22.727803 47
+C 0.-1451822804 2009-07-30 15:47:22.729198
+B 0.-1447142132 2009-07-30 15:47:22.752054 GET /space-travel/plans/space-logs.txt
+I 0.-1447142132 2009-07-30 15:47:22.752441 0
+B 0.-1452075572 2009-07-30 15:47:23.519245 POST /approve-photo
+I 0.-1452075572 2009-07-30 15:47:23.568230 166
+A 0.-1451822804 2009-07-30 15:47:25.147638 500 84
+E 0.-1451822804 2009-07-30 15:47:25.147826
+C 0.-1447142132 2009-07-30 15:47:25.148249
+A 0.-1447142132 2009-07-30 15:47:25.152085 200 9229
+E 0.-1447142132 2009-07-30 15:47:25.152360
+C 0.-1452075572 2009-07-30 15:47:25.152746
+B 0.-1451734452 2009-07-30 15:47:25.355541 GET /space-travel/plans/cryostasis.txt
+I 0.-1451734452 2009-07-30 15:47:25.355887 0
+A 0.-1452075572 2009-07-30 15:47:25.405454 200 17
+E 0.-1452075572 2009-07-30 15:47:25.405612
+C 0.-1451734452 2009-07-30 15:47:25.406003
+A 0.-1451734452 2009-07-30 15:47:25.409328 200 6169
+E 0.-1451734452 2009-07-30 15:47:25.409483
+B 0.-1451822804 2009-07-30 15:47:25.437048 GET /faqs/how-to-recognize-lazer-fire.html
+I 0.-1451822804 2009-07-30 15:47:25.437329 0
+C 0.-1451822804 2009-07-30 15:47:25.437536
+A 0.-1451822804 2009-07-30 15:47:25.627659 200 68080
+B 0.-1302919956 2009-07-30 15:47:25.628008 POST /submit-photo
+E 0.-1451822804 2009-07-30 15:47:25.628366
+I 0.-1302919956 2009-07-30 15:47:25.628444 55
+B 0.-1302917172 2009-07-30 15:47:25.628924 POST /login
+C 0.-1302919956 2009-07-30 15:47:25.629222
+I 0.-1302917172 2009-07-30 15:47:25.629321 117
+B 0.-1449313684 2009-07-30 15:47:26.041970 GET /favicon.png
+I 0.-1449313684 2009-07-30 15:47:26.042345 0
+A 0.-1302919956 2009-07-30 15:47:26.099986 200 41
+E 0.-1302919956 2009-07-30 15:47:26.100156
+C 0.-1302917172 2009-07-30 15:47:26.100735
+A 0.-1302917172 2009-07-30 15:47:26.116404 302 10
+E 0.-1302917172 2009-07-30 15:47:26.116563
+C 0.-1449313684 2009-07-30 15:47:26.117086
+A 0.-1449313684 2009-07-30 15:47:26.251358 404 50862
+B 0.-1428979956 2009-07-30 15:47:26.251489 GET /faqs/how-to-recognize-lazer-fire.html
+E 0.-1449313684 2009-07-30 15:47:26.252164
+I 0.-1428979956 2009-07-30 15:47:26.252274 0
+C 0.-1428979956 2009-07-30 15:47:26.252952
+A 0.-1428979956 2009-07-30 15:47:26.437438 200 68080
+E 0.-1428979956 2009-07-30 15:47:26.437816
+B 0.-1447439956 2009-07-30 15:47:26.443603 GET /space-travelers/famous/kirk.jpg
+I 0.-1447439956 2009-07-30 15:47:26.443993 0
+C 0.-1447439956 2009-07-30 15:47:26.444325
+A 0.-1447439956 2009-07-30 15:47:26.462018 200 12363
+E 0.-1447439956 2009-07-30 15:47:26.462267
+B 0.-1452020020 2009-07-30 15:47:26.703761 GET /space-travel/plans/moon-buggy.jpg
+I 0.-1452020020 2009-07-30 15:47:26.704142 0
+C 0.-1452020020 2009-07-30 15:47:26.704459
+A 0.-1452020020 2009-07-30 15:47:26.708426 200 13352
+E 0.-1452020020 2009-07-30 15:47:26.708688
+B 0.-1316900564 2009-07-30 15:47:26.902012 GET /space-travel/plans/moon-base.jpg
+I 0.-1316900564 2009-07-30 15:47:26.902406 0
+C 0.-1316900564 2009-07-30 15:47:26.902714
+A 0.-1316900564 2009-07-30 15:47:26.906228 200 41724
+E 0.-1316900564 2009-07-30 15:47:26.906526
+B 0.-1316900500 2009-07-30 15:47:26.923493 GET /space-travel/plans/launchpad.html
+I 0.-1316900500 2009-07-30 15:47:26.923870 0
+C 0.-1316900500 2009-07-30 15:47:26.924480
+B 0.-1451735092 2009-07-30 15:47:26.926861 GET /space-travel/plans/space-suit.jpg
+I 0.-1451735092 2009-07-30 15:47:26.927643 0
+A 0.-1316900500 2009-07-30 15:47:26.928712 200 23930
+E 0.-1316900500 2009-07-30 15:47:26.929032
+C 0.-1451735092 2009-07-30 15:47:26.929398
+A 0.-1451735092 2009-07-30 15:47:26.932609 200 8874
+E 0.-1451735092 2009-07-30 15:47:26.932822
+B 0.-1449537908 2009-07-30 15:47:27.072593 GET /planets/saturn.html
+I 0.-1449537908 2009-07-30 15:47:27.072996 0
+C 0.-1449537908 2009-07-30 15:47:27.073267
+B 0.-1446157716 2009-07-30 15:47:27.804192 GET /space-travel/plans/space-diary.txt
+I 0.-1446157716 2009-07-30 15:47:27.804592 0
+B 0.-1451398452 2009-07-30 15:47:28.142720 GET /space-travel/ships/tardis.html
+I 0.-1451398452 2009-07-30 15:47:28.143129 0
+A 0.-1449537908 2009-07-30 15:47:36.766928 200 80348
+E 0.-1449537908 2009-07-30 15:47:36.767267
+C 0.-1446157716 2009-07-30 15:47:36.767650
+A 0.-1446157716 2009-07-30 15:47:36.771444 200 11509
+E 0.-1446157716 2009-07-30 15:47:36.771662
+C 0.-1451398452 2009-07-30 15:47:36.772062
+A 0.-1451398452 2009-07-30 15:47:37.092002 200 140899
+E 0.-1451398452 2009-07-30 15:47:37.092674
+B 0.-1449537620 2009-07-30 15:47:37.250550 GET /space-travel/plans/supplies.txt
+I 0.-1449537620 2009-07-30 15:47:37.250985 0
+C 0.-1449537620 2009-07-30 15:47:37.251283
+A 0.-1449537620 2009-07-30 15:47:37.254655 200 4634
+E 0.-1449537620 2009-07-30 15:47:37.254822
+B 0.-1432095860 2009-07-30 15:47:37.416180 GET /moons/io.html
+I 0.-1432095860 2009-07-30 15:47:37.416546 0
+C 0.-1432095860 2009-07-30 15:47:37.416879
+B 0.-1452077908 2009-07-30 15:47:38.021796 GET /space-travel/plans/lunar-cycles.html
+I 0.-1452077908 2009-07-30 15:47:38.022227 0
+B 0.-1452077108 2009-07-30 15:47:38.024492 GET /stars/alpha-centauri.html
+I 0.-1452077108 2009-07-30 15:47:38.024763 0
+A 0.-1432095860 2009-07-30 15:47:45.716409 200 84416
+B 0.-1450432916 2009-07-30 15:47:45.716542 GET /faqs/how-to-charge-lazers.html
+I 0.-1450432916 2009-07-30 15:47:45.717316 0
+E 0.-1432095860 2009-07-30 15:47:45.717481
+C 0.-1452077908 2009-07-30 15:47:45.718153
+A 0.-1452077908 2009-07-30 15:47:45.721679 200 23930
+E 0.-1452077908 2009-07-30 15:47:45.721959
+C 0.-1452077108 2009-07-30 15:47:45.722393
+B 0.-1452079956 2009-07-30 15:47:46.122502 GET /space-travel/plans/space-logs.txt
+I 0.-1452079956 2009-07-30 15:47:46.122892 0
+B 0.-1450441812 2009-07-30 15:47:46.893894 GET /planets/jupiter.html
+I 0.-1450441812 2009-07-30 15:47:46.895532 0
+A 0.-1452077108 2009-07-30 15:47:47.224805 200 85562
+E 0.-1452077108 2009-07-30 15:47:47.225152
+C 0.-1450432916 2009-07-30 15:47:47.225629
+A 0.-1450432916 2009-07-30 15:47:47.576384 200 72972
+E 0.-1450432916 2009-07-30 15:47:47.576766
+C 0.-1452079956 2009-07-30 15:47:47.577168
+A 0.-1452079956 2009-07-30 15:47:47.580553 200 9229
+E 0.-1452079956 2009-07-30 15:47:47.580769
+C 0.-1450441812 2009-07-30 15:47:47.581132
+B 0.-1316936084 2009-07-30 15:47:47.877642 GET /space-travelers/famous/kirk.jpg
+I 0.-1316936084 2009-07-30 15:47:47.878035 0
+B 0.-1459198900 2009-07-30 15:47:49.483239 GET /space-travel/plans/signals.html
+I 0.-1459198900 2009-07-30 15:47:49.483620 0
+B 0.-1459203636 2009-07-30 15:47:50.804934 POST /ufo-sightings/report
+I 0.-1459203636 2009-07-30 15:47:50.805338 0
+A 0.-1450441812 2009-07-30 15:47:54.920706 200 84573
+E 0.-1450441812 2009-07-30 15:47:54.921054
+C 0.-1316936084 2009-07-30 15:47:54.921448
+A 0.-1316936084 2009-07-30 15:47:54.937589 200 12363
+E 0.-1316936084 2009-07-30 15:47:54.937871
+C 0.-1459198900 2009-07-30 15:47:54.938248
+A 0.-1459198900 2009-07-30 15:47:54.942024 200 28192
+E 0.-1459198900 2009-07-30 15:47:54.942355
+C 0.-1459203636 2009-07-30 15:47:54.942714
+A 0.-1459203636 2009-07-30 15:47:55.124368 200 72121
+E 0.-1459203636 2009-07-30 15:47:55.124704
+B 0.-1440558580 2009-07-30 15:47:55.210668 GET /js/photo.js
+I 0.-1440558580 2009-07-30 15:47:55.211064 0
+C 0.-1440558580 2009-07-30 15:47:55.211309
+A 0.-1440558580 2009-07-30 15:47:55.214851 200 48461
+E 0.-1440558580 2009-07-30 15:47:55.215188
+B 0.-1449243764 2009-07-30 15:47:55.283181 GET /space-travelers/famous/spock.jpg
+I 0.-1449243764 2009-07-30 15:47:55.283590 0
+C 0.-1449243764 2009-07-30 15:47:55.283844
+A 0.-1449243764 2009-07-30 15:47:55.299571 200 12363
+E 0.-1449243764 2009-07-30 15:47:55.299816
+B 0.-1450432884 2009-07-30 15:47:55.305871 GET /space-travelers/famous/kirk.jpg
+I 0.-1450432884 2009-07-30 15:47:55.306209 0
+C 0.-1450432884 2009-07-30 15:47:55.306458
+A 0.-1450432884 2009-07-30 15:47:55.321748 200 12363
+E 0.-1450432884 2009-07-30 15:47:55.321997
+B 0.-1435269268 2009-07-30 15:47:55.369140 GET /stories/aliens-posing-as-humans.html
+I 0.-1435269268 2009-07-30 15:47:55.369547 0
+C 0.-1435269268 2009-07-30 15:47:55.369792
+B 0.-1448404052 2009-07-30 15:47:55.473937 GET /space-travel/ships/soyuz.html
+I 0.-1448404052 2009-07-30 15:47:55.474327 0
+B 0.-1459223188 2009-07-30 15:47:55.759673 GET /space-travel/plans/signals.html
+I 0.-1459223188 2009-07-30 15:47:55.760064 0
+A 0.-1435269268 2009-07-30 15:47:56.249524 200 53951
+E 0.-1435269268 2009-07-30 15:47:56.249867
+C 0.-1448404052 2009-07-30 15:47:56.250269
+A 0.-1448404052 2009-07-30 15:47:56.388066 404 50858
+E 0.-1448404052 2009-07-30 15:47:56.388716
+C 0.-1459223188 2009-07-30 15:47:56.389102
+A 0.-1459223188 2009-07-30 15:47:56.392628 200 28192
+E 0.-1459223188 2009-07-30 15:47:56.393049
+B 0.-1332223444 2009-07-30 15:47:56.650638 GET /space-travel/plans/orbit.html
+I 0.-1332223444 2009-07-30 15:47:56.651035 0
+C 0.-1332223444 2009-07-30 15:47:56.651363
+A 0.-1332223444 2009-07-30 15:47:56.655008 200 8190
+E 0.-1332223444 2009-07-30 15:47:56.655206
+B 0.-1414750484 2009-07-30 15:47:56.666147 GET /space-travel/plans/signals.html
+I 0.-1414750484 2009-07-30 15:47:56.666988 0
+C 0.-1414750484 2009-07-30 15:47:56.667249
+A 0.-1414750484 2009-07-30 15:47:56.670341 304 0
+E 0.-1414750484 2009-07-30 15:47:56.670491
+B 0.-1459201556 2009-07-30 15:47:56.702162 GET /favicon.png
+I 0.-1459201556 2009-07-30 15:47:56.702495 0
+C 0.-1459201556 2009-07-30 15:47:56.702761
+A 0.-1459201556 2009-07-30 15:47:56.835660 404 50859
+E 0.-1459201556 2009-07-30 15:47:56.836354
+B 0.-1452006804 2009-07-30 15:47:56.837006 GET /space-travel/plans/visor.jpg
+I 0.-1452006804 2009-07-30 15:47:56.837398 0
+B 0.-1451986836 2009-07-30 15:47:56.837899 GET /space-travel/plans/orbit.html
+I 0.-1451986836 2009-07-30 15:47:56.838264 0
+C 0.-1452006804 2009-07-30 15:47:56.838505
+A 0.-1452006804 2009-07-30 15:47:56.842045 200 61967
+E 0.-1452006804 2009-07-30 15:47:56.842451

Modified: zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tests.py
===================================================================
--- zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tests.py	2009-08-26 21:33:02 UTC (rev 103242)
+++ zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tests.py	2009-08-26 21:43:17 UTC (rev 103243)
@@ -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/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.py
===================================================================
--- zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.py	2009-08-26 21:33:02 UTC (rev 103242)
+++ zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.py	2009-08-26 21:43:17 UTC (rev 103243)
@@ -15,9 +15,12 @@
 """Yet another trace log analysis tool
 """
 
-import datetime, optparse, sys
+import datetime
+import optparse
+import sys
+import time
 
-class Request:
+class Request(object):
 
     output_bytes = '-'
 
@@ -53,8 +56,9 @@
     def total_seconds(self):
         return (self.end - self.start).seconds
 
-class Times:
 
+class Times(object):
+
     tid = 1l
 
     def __init__(self):
@@ -113,17 +117,29 @@
         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 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 +187,9 @@
         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()[1]
+        dt = parse_datetime(strtime)
         if dt == restart:
             continue
         while dt > restart:
@@ -215,7 +231,8 @@
                     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
@@ -233,7 +250,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
@@ -344,7 +366,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=%5d " % (
         len(requests), input, wait, apps, output),
     if n:
         print "N=%4d %10.2f %10.2f" % (n, spr/n, spa/n)
@@ -363,7 +385,7 @@
     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))
     print '</tr>'
@@ -431,7 +453,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 +470,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:
 

Added: zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.txt
===================================================================
--- zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.txt	                        (rev 0)
+++ zc.zservertracelog/branches/asmith-tracereport-fixes/src/zc/zservertracelog/tracereport.txt	2009-08-26 21:43:17 UTC (rev 103243)
@@ -0,0 +1,111 @@
+===================
+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', sample_log])
+    <BLANKLINE>
+    URL statistics:
+       Impact count    min median   mean    max hangs
+    ========= ===== ====== ====== ====== ====== =====
+          9.0     1      9   9.00   9.00      9     0 /planets/saturn.html -> 200
+          8.0     1      8   8.00   8.00      8     0 /moons/io.html -> 200
+          7.0     1      7   7.00   7.00      7     0 /planets/jupiter.html -> 200
+          2.0     1      2   2.00   2.00      2     0 /constellations/andromeda.html -> 500
+          1.0     1      1   1.00   1.00      1     0 /stars/alpha-centauri.html -> 200
+
+This can also be displayed as HTML.
+
+    >>> zc.zservertracelog.tracereport.main(
+    ...     ['--summary-only', '--html', 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="u54">9.0</td><td>1</td><td>9</td><td>9</td><td>9.0</td><td>9</td><td>0</td>
+    <td>/planets/saturn.html -> 200</td>
+    </tr>
+    <tr style="background: lightgrey;">
+    <td><a name="u58">8.0</td><td>1</td><td>8</td><td>8</td><td>8.0</td><td>8</td><td>0</td>
+    <td>/moons/io.html -> 200</td>
+    </tr>
+    <tr>
+    <td><a name="u62">7.0</td><td>1</td><td>7</td><td>7</td><td>7.0</td><td>7</td><td>0</td>
+    <td>/planets/jupiter.html -> 200</td>
+    </tr>
+    <tr style="background: lightgrey;">
+    <td><a name="u41">2.0</td><td>1</td><td>2</td><td>2</td><td>2.0</td><td>2</td><td>0</td>
+    <td>/constellations/andromeda.html -> 500</td>
+    </tr>
+    <tr>
+    <td><a name="u60">1.0</td><td>1</td><td>1</td><td>1</td><td>1.0</td><td>1</td><td>0</td>
+    <td>/stars/alpha-centauri.html -> 200</td>
+    </tr>
+    </table>
+    </body></html>
+
+TODO: test full report
+TODO: redo examples for sub-second resolution



More information about the Checkins mailing list