[Checkins] SVN: zc.zservertracelog/branches/dev/ Refined a bit. :)
Jim Fulton
jim at zope.com
Fri Apr 27 16:47:49 EDT 2007
Log message for revision 74870:
Refined a bit. :)
Changed:
_U zc.zservertracelog/branches/dev/
A zc.zservertracelog/branches/dev/README.txt
U zc.zservertracelog/branches/dev/buildout.cfg
A zc.zservertracelog/branches/dev/setup.py
U zc.zservertracelog/branches/dev/src/zc/zservertracelog/__init__.py
U zc.zservertracelog/branches/dev/src/zc/zservertracelog/configure.zcml
A zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracelog.py
A zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracereport.py
-=-
Property changes on: zc.zservertracelog/branches/dev
___________________________________________________________________
Name: svn:ignore
+ develop-eggs
parts
dist
bin
trace.log
Added: zc.zservertracelog/branches/dev/README.txt
===================================================================
--- zc.zservertracelog/branches/dev/README.txt 2007-04-27 20:07:19 UTC (rev 74869)
+++ zc.zservertracelog/branches/dev/README.txt 2007-04-27 20:47:49 UTC (rev 74870)
@@ -0,0 +1,60 @@
+***********************
+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.
+
+- Request begins:
+
+ B -1214390740 2007-04-27T20:16:55 GET /
+
+ Includes the request method and path.
+
+- Got request input:
+
+ I -1214390740 2007-04-27T20:16:55 0
+
+ Includes the request content length.
+
+- Entered application thread:
+
+ C -1214390740 2007-04-27T20:16:55
+
+- Application done:
+
+ A -1223774356 2007-04-27T20:16:55 500 84
+
+ Includes the response content length.
+
+- Request done:
+
+ E -1223774356 2007-04-27T20:16:55
+
+In addition, application startup is logged with an 'S' record:
+
+ S 0 2007-04-27T20:24:29
+
+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.tracelog
+ 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.
+
+
+
Property changes on: zc.zservertracelog/branches/dev/README.txt
___________________________________________________________________
Name: svn:eol-style
+ native
Modified: zc.zservertracelog/branches/dev/buildout.cfg
===================================================================
--- zc.zservertracelog/branches/dev/buildout.cfg 2007-04-27 20:07:19 UTC (rev 74869)
+++ zc.zservertracelog/branches/dev/buildout.cfg 2007-04-27 20:47:49 UTC (rev 74870)
@@ -1,28 +1,39 @@
[buildout]
develop = .
-parts = instance
+parts = instance tracereport
[zope3]
recipe = zc.recipe.zope3checkout
-url = svn://svn.zope.org/repos/main/Zope3/tags/3.3.0
+url = svn://svn.zope.org/repos/main/Zope3/trunk
[app]
recipe = zc.zope3recipes:app
eggs = zc.zservertracelog
servers = zserver
-site.zcml = <include package="zope.app" />
- <principal
- id="zope.manager"
- title="Manager"
- login="jim"
- password_manager="SHA1"
- password="40bd001563085fc35165329ea1ff5c5ecbdbbeef"
- />
- <grant
- role="zope.Manager"
- principal="zope.manager"
- />
- <includeOverrides package="zc.zservertracelog" />
+site.zcml =
+ <include package="zope.app.zcmlfiles" />
+ <include package="zope.app.securitypolicy" />
+ <include package="zope.app.securitypolicy" file="meta.zcml" />
+ <include package="zope.app.authentication" />
+ <securityPolicy
+ component="zope.app.securitypolicy.zopepolicy.ZopeSecurityPolicy" />
+ <role id="zope.Anonymous" title="Everybody"
+ description="All users have this role implicitly" />
+ <role id="zope.Manager" title="Site Manager" />
+ <role id="zope.Member" title="Site Member" />
+ <grantAll role="zope.Manager" />
+ <principal
+ id="zope.manager"
+ title="Manager"
+ login="jim"
+ password_manager="SHA1"
+ password="40bd001563085fc35165329ea1ff5c5ecbdbbeef"
+ />
+ <grant
+ role="zope.Manager"
+ principal="zope.manager"
+ />
+ <includeOverrides package="zc.zservertracelog" />
[instance]
recipe = zc.zope3recipes:instance
@@ -42,3 +53,7 @@
[database]
recipe = zc.recipe.filestorage
+
+[tracereport]
+recipe = zc.recipe.egg:script
+eggs = zc.zservertracelog
Added: zc.zservertracelog/branches/dev/setup.py
===================================================================
--- zc.zservertracelog/branches/dev/setup.py 2007-04-27 20:07:19 UTC (rev 74869)
+++ zc.zservertracelog/branches/dev/setup.py 2007-04-27 20:47:49 UTC (rev 74870)
@@ -0,0 +1,24 @@
+from setuptools import setup, find_packages
+
+entry_points = """
+[console_scripts]
+tracereport = zc.zservertracelog.tracereport:main
+"""
+
+name = 'zc.zservertracelog'
+setup(
+ name = name,
+ version = '0.1dev',
+ author = 'Jim Fulton',
+ author_email = 'jim at zope.com',
+ description = 'Zope 3 tracelog implementation for zserver',
+ license = 'ZPL 2.1',
+ keywords = 'zope3',
+
+ packages = find_packages('src'),
+ namespace_packages = ['zc'],
+ package_dir = {'': 'src'},
+ install_requires = 'setuptools',
+ zip_safe = False,
+ entry_points=entry_points,
+ )
Property changes on: zc.zservertracelog/branches/dev/setup.py
___________________________________________________________________
Name: svn:keywords
+ Id
Name: svn:eol-style
+ native
Modified: zc.zservertracelog/branches/dev/src/zc/zservertracelog/__init__.py
===================================================================
--- zc.zservertracelog/branches/dev/src/zc/zservertracelog/__init__.py 2007-04-27 20:07:19 UTC (rev 74869)
+++ zc.zservertracelog/branches/dev/src/zc/zservertracelog/__init__.py 2007-04-27 20:47:49 UTC (rev 74870)
@@ -1,92 +1 @@
-##############################################################################
#
-# Copyright (c) 2005 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.
-#
-##############################################################################
-"""Crude Tracelog Hack for ZServer
-"""
-import datetime, re, logging
-
-from zope.server.http.commonaccesslogger import CommonAccessLogger
-from zope.server.http import wsgihttpserver
-import zope.server.http.httprequestparser
-
-import zope.server.http.httpserverchannel
-from zope.app.server import servertype
-
-from zope.app.wsgi import WSGIPublisherApplication
-
-logger = logging.getLogger('zc.tracelog')
-
-def now():
- return datetime.datetime.utcnow().replace(microsecond=0).isoformat()
-
-class Parser(zope.server.http.httprequestparser.HTTPRequestParser):
-
- def __init__(self, x):
- self._Channel__B = 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)
- zope.server.http.httpserverchannel.HTTPServerChannel.handle_request(
- self, parser)
-
-class Server(wsgihttpserver.WSGIHTTPServer):
-
- channel_class = Channel
-
- def executeRequest(self, task):
- """Overrides HTTPServer.executeRequest()."""
- logger.info("C %s %s", id(task.channel), now())
- env = task.getCGIEnvironment()
- env['wsgi.input'] = task.request_data.getBodyStream()
-
- def start_response(status, headers):
- # Prepare the headers for output
- status, reason = re.match('([0-9]*) (.*)', status).groups()
- task.setResponseStatus(status, reason)
- task.appendResponseHeaders(['%s: %s' % i for i in headers])
-
- # Return the write method used to write the response data.
- return wsgihttpserver.fakeWrite
-
- # Call the application to handle the request and write a response
- response = self.application(env, start_response)
- length = [h.split(': ')[1].strip()
- for h in task.accumulated_headers
- if h.lower().startswith('content-length: ')]
- if length:
- length = length[0]
- else:
- length = '?'
- logger.info("A %s %s %s %s", id(self), now(),
- task.status, length)
- task.write(response)
- logger.info("E %s %s", id(self), now())
-
-http = servertype.ServerType(
- Server,
- WSGIPublisherApplication,
- CommonAccessLogger,
- 8080, True)
-
-pmhttp = servertype.ServerType(
- wsgihttpserver.PMDBWSGIHTTPServer,
- WSGIPublisherApplication,
- CommonAccessLogger,
- 8013, True)
Modified: zc.zservertracelog/branches/dev/src/zc/zservertracelog/configure.zcml
===================================================================
--- zc.zservertracelog/branches/dev/src/zc/zservertracelog/configure.zcml 2007-04-27 20:07:19 UTC (rev 74869)
+++ zc.zservertracelog/branches/dev/src/zc/zservertracelog/configure.zcml 2007-04-27 20:47:49 UTC (rev 74870)
@@ -2,14 +2,15 @@
<utility
name="WSGI-HTTP"
- component=".http"
+ component=".tracelog.http"
provides="zope.app.server.servertype.IServerType"
/>
<utility
name="WSGI-PostmortemDebuggingHTTP"
- component=".pmhttp"
+ component=".tracelog.pmhttp"
provides="zope.app.server.servertype.IServerType"
/>
+ <subscriber handler=".tracelog.started" />
</configure>
Added: zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracelog.py
===================================================================
--- zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracelog.py 2007-04-27 20:07:19 UTC (rev 74869)
+++ zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracelog.py 2007-04-27 20:47:49 UTC (rev 74870)
@@ -0,0 +1,100 @@
+##############################################################################
+#
+# Copyright (c) 2005 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.
+#
+##############################################################################
+"""Crude Tracelog Hack for ZServer
+"""
+import datetime, re, logging
+
+import zope.component
+
+from zope.server.http.commonaccesslogger import CommonAccessLogger
+from zope.server.http import wsgihttpserver
+import zope.server.http.httprequestparser
+
+import zope.server.http.httpserverchannel
+from zope.app.server import servertype
+
+from zope.app.wsgi import WSGIPublisherApplication
+
+import zope.app.appsetup.interfaces
+
+logger = logging.getLogger('zc.tracelog')
+
+def now():
+ return datetime.datetime.utcnow().replace(microsecond=0).isoformat()
+
+class Parser(zope.server.http.httprequestparser.HTTPRequestParser):
+
+ def __init__(self, x):
+ self._Channel__B = 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)
+ zope.server.http.httpserverchannel.HTTPServerChannel.handle_request(
+ self, parser)
+
+class Server(wsgihttpserver.WSGIHTTPServer):
+
+ channel_class = Channel
+
+ def executeRequest(self, task):
+ """Overrides HTTPServer.executeRequest()."""
+ logger.info("C %s %s", id(task.channel), now())
+ env = task.getCGIEnvironment()
+ env['wsgi.input'] = task.request_data.getBodyStream()
+
+ def start_response(status, headers):
+ # Prepare the headers for output
+ status, reason = re.match('([0-9]*) (.*)', status).groups()
+ task.setResponseStatus(status, reason)
+ task.appendResponseHeaders(['%s: %s' % i for i in headers])
+
+ # Return the write method used to write the response data.
+ return wsgihttpserver.fakeWrite
+
+ # Call the application to handle the request and write a response
+ response = self.application(env, start_response)
+ length = [h.split(': ')[1].strip()
+ for h in task.accumulated_headers
+ if h.lower().startswith('content-length: ')]
+ if length:
+ length = length[0]
+ else:
+ length = '?'
+ logger.info("A %s %s %s %s", id(self), now(),
+ task.status, length)
+ task.write(response)
+ logger.info("E %s %s", id(self), now())
+
+http = servertype.ServerType(
+ Server,
+ WSGIPublisherApplication,
+ CommonAccessLogger,
+ 8080, True)
+
+pmhttp = servertype.ServerType(
+ wsgihttpserver.PMDBWSGIHTTPServer,
+ WSGIPublisherApplication,
+ CommonAccessLogger,
+ 8013, True)
+
+ at zope.component.adapter(zope.app.appsetup.interfaces.IProcessStartingEvent)
+def started(event):
+ logger.info("S 0 %s", now())
Property changes on: zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracelog.py
___________________________________________________________________
Name: svn:keywords
+ Id
Name: svn:eol-style
+ native
Added: zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracereport.py
===================================================================
--- zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracereport.py 2007-04-27 20:07:19 UTC (rev 74869)
+++ zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracereport.py 2007-04-27 20:47:49 UTC (rev 74870)
@@ -0,0 +1,477 @@
+##############################################################################
+#
+# Copyright (c) 2006 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.
+#
+##############################################################################
+"""Yet another lag analysis tool
+
+
+
+$Id$
+"""
+
+import datetime, optparse, sys
+
+class Request:
+
+ output_bytes = '-'
+
+ def __init__(self, start, method, url):
+ self.method = method
+ self.url = url
+ self.start = start
+ self.state = 'input'
+
+ def I(self, input_time, input_bytes):
+ self.input_time = input_time
+ self.input_bytes = input_bytes
+ self.state = 'wait'
+
+ def C(self, start_app_time):
+ self.start_app_time = start_app_time
+ self.state = 'app'
+
+ def A(self, app_time, response, output_bytes):
+ self.app_time = app_time
+ self.response = response
+ self.output_bytes = output_bytes
+ self.state = 'output'
+
+ def E(self, end):
+ self.end = end
+
+ @property
+ def app_seconds(self):
+ return (self.app_time - self.start_app_time).seconds
+
+ @property
+ def total_seconds(self):
+ return (self.end - self.start).seconds
+
+class Times:
+
+ tid = 1l
+
+ def __init__(self):
+ self.times = []
+ self.hangs = 0
+ Times.tid += 1
+ self.tid = Times.tid # generate a unique id
+
+ def finished(self, request):
+ self.times.append(request.app_seconds)
+
+ def hung(self):
+ self.hangs += 1
+
+ def impact(self):
+ times = self.times
+ if not times:
+ self.median = self.mean = self.impact = 0
+ return 0
+ self.times.sort()
+ n = len(times)
+ if n % 2:
+ m = times[(n+1)/2-1]
+ else:
+ m = .5 * (times[n/2]+times[n/2-1])
+ self.median = m
+ self.mean = sum(times)/n
+ self.impact = self.mean * (n+self.hangs)
+ return self.impact
+
+ def __str__(self):
+ times = self.times
+ if not times:
+ return " 0 %5d" % (
+ self.hangs)
+
+ n = len(times)
+ m = self.median
+ return "%9.1f %5d %6.0f %6.2f %6.2f %6.0f %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)
+ else:
+ 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)
+
+def parsedt(s):
+ date, time = s.split('T')
+ return datetime.datetime(*(
+ map(int, date.split('-'))
+ +
+ map(int, time.split(':'))
+ ))
+
+def main(args=None):
+ if args is None:
+ args = sys.argv[1:]
+
+ options, args = parser.parse_args(args)
+ if options.event_log:
+ restarts = find_restarts(options.event_log)
+ else:
+ restarts = []
+
+ restarts.append(datetime.datetime.utcnow()+datetime.timedelta(1000))
+
+ if options.html:
+ print_app_requests = print_app_requests_html
+ output_minute = output_minute_html
+ output_stats = output_stats_html
+ minutes_header = minutes_header_html
+ minutes_footer = minutes_footer_html
+ print '<html title="trace log statistics"><body>'
+ else:
+ print_app_requests = print_app_requests_text
+ output_minute = output_minute_text
+ output_stats = output_stats_text
+ minutes_header = minutes_header_text
+ minutes_footer = minutes_footer_text
+
+
+ urls = {}
+ [file] = args
+ lmin = ldt = None
+ requests = {}
+ input = apps = output = n = wait = 0
+ spr = spa = 0.0
+ restart = restarts.pop(0)
+ minutes_header()
+ remove_prefix = options.remove_prefix
+ for record in open(file):
+ record = record.split()
+ typ, rid, dt = record[:3]
+ min = dt[:-3]
+ dt = parsedt(dt)
+ if dt == restart:
+ continue
+ while dt > restart:
+ print_app_requests(requests, ldt,
+ options.old_requests,
+ options.app_requests,
+ urls,
+ "\nLeft over:")
+ record_hung(urls, requests)
+ requests = {}
+ input = apps = output = n = wait = 0
+ spr = spa = 0.0
+ restart = restarts.pop(0)
+ ldt = dt
+
+ if min != lmin:
+ if lmin is not None:
+ output_minute(lmin, requests, input, wait, apps, output, n, spr, spa)
+ if apps > options.apps:
+ print_app_requests(requests, dt,
+ options.old_requests,
+ options.app_requests,
+ urls,
+ )
+ lmin = min
+ spr = 0.0
+ spa = 0.0
+ n = 0
+
+ if typ == 'B':
+ if rid in requests:
+ request = requests[rid]
+ if request.state == 'output':
+ output -= 1
+ elif request.state == 'app':
+ apps -= 1
+ else:
+ input -= 1
+
+ input += 1
+ request = Request(dt, *record[3:5])
+ 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
+ wait += 1
+ requests[rid].I(dt, record[3])
+ elif typ == 'C':
+ if rid in requests:
+ wait -= 1
+ apps += 1
+ requests[rid].C(dt)
+ elif typ == 'A':
+ if rid in requests:
+ apps -= 1
+ output += 1
+ requests[rid].A(dt, *record[3:5])
+ elif typ == 'E':
+ if rid in requests:
+ output -= 1
+ request = requests.pop(rid)
+ request.E(dt)
+ spr += request.total_seconds
+ spa += request.app_seconds
+ n += 1
+ times = urls[request.url]
+ times.finished(request)
+ elif typ in 'SX':
+ print_app_requests(requests, ldt,
+ options.old_requests,
+ options.app_requests,
+ urls,
+ "\nLeft over:")
+ record_hung(urls, requests)
+ requests = {}
+ input = apps = output = n = wait = 0
+ spr = spa = 0.0
+ else:
+ print 'WTF', record
+
+ print_app_requests(requests, dt,
+ options.old_requests,
+ options.app_requests,
+ urls,
+ "Left over:")
+
+ minutes_footer()
+
+ output_stats(urls)
+
+ if options.html:
+ print '</body></html>'
+
+def output_stats_text(urls):
+ print
+ print 'URL statistics:'
+ print " Impact count min median mean max hangs"
+ print "========= ===== ====== ====== ====== ====== ====="
+ urls = [(times.impact(), url, times)
+ for (url, times) in urls.iteritems()
+ ]
+ urls.sort()
+ urls.reverse()
+ for (_, url, times) in urls:
+ if times.impact > 0 or times.hangs:
+ print times, url
+
+def output_stats_html(urls):
+ print
+ print 'URL statistics:'
+ print '<table border="1">'
+ print '<tr><th>Impact</th><th>count</th><th>min</th>'
+ print '<th>median</th><th>mean</th><th>max</th><th>hangs</th></tr>'
+ urls = [(times.impact(), url, times)
+ for (url, times) in urls.iteritems()
+ ]
+ urls.sort()
+ urls.reverse()
+ for (_, url, times) in urls:
+ if times.impact > 0 or times.hangs:
+ print '<tr>'
+ times.html()
+ print td(url)
+ print '</tr>'
+ print '</table>'
+
+def minutes_header_text():
+ print
+ print " minute req input wait app output"
+ print "================ ===== ===== ===== ===== ======"
+
+def minutes_footer_text():
+ print
+
+def minutes_header_html():
+ print '<table border="2">'
+ print "<tr>"
+ print '<th>Minute</th>'
+ print '<th>Requests</th>'
+ print '<th>Requests inputing</th>'
+ print '<th>Requests waiting</th>'
+ print '<th>Requests executing</th>'
+ print '<th>Requests outputing</th>'
+ print '<th>Requests completed</th>'
+ print '<th>Mean Seconds Per Request Total</th>'
+ print '<th>Mean Seconds Per Request in App</th>'
+ print "</tr>"
+
+def minutes_footer_html():
+ 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 " % (
+ len(requests), input, wait, apps, output),
+ if n:
+ print "N=%4d %10.2f %10.2f" % (n, spr/n, spa/n)
+ else:
+ print
+
+def td(*values):
+ return ''.join([("<td>%s</td>" % s) for s in values])
+
+def output_minute_html(lmin, requests, input, wait, apps, output, n, spr, spa):
+ print '<tr>'
+ apps = '<font size="+2"><strong>%s</strong></font>' % apps
+ print td(lmin.replace('T', ' '), len(requests), input, wait, apps, output)
+ if n:
+ print td(n, "%10.2f" % (spr/n), "%10.2f" % (spa/n))
+ print '</tr>'
+
+def find_restarts(event_log):
+ result = []
+ for l in open(event_log):
+ if l.strip().endswith("Zope Ready to handle requests"):
+ result.append(parsedt(l.split()[0]))
+ return result
+
+def record_hung(urls, requests):
+ for request in requests.itervalues():
+ times = urls.get(request.url)
+ if times is None:
+ times = urls[request.url] = Times()
+ times.hung()
+
+def print_app_requests_text(requests, dt, min_seconds, max_requests, urls,
+ label=''):
+ requests = [
+ ((dt-request.start).seconds, request)
+ for request in requests.values()
+ if request.state == 'app'
+ ]
+
+ urls = {}
+ for s, request in requests:
+ urls[request.url] = urls.get(request.url, 0) + 1
+
+ requests.sort()
+ requests.reverse()
+ for s, request in requests[:max_requests]:
+ if s < min_seconds:
+ continue
+ if label:
+ print label
+ label = ''
+ url = request.url
+ repeat = urls[url]
+ if repeat > 1:
+ print s, "R=%d" % repeat, url
+ else:
+ print s, url
+
+def print_app_requests_html(requests, dt, min_seconds, max_requests, allurls,
+ label=''):
+ requests = [
+ ((dt-request.start).seconds, request)
+ for request in requests.values()
+ if request.state == 'app'
+ ]
+
+ urls = {}
+ for s, request in requests:
+ urls[request.url] = urls.get(request.url, 0) + 1
+
+ requests.sort()
+ requests.reverse()
+ printed = False
+ for s, request in requests[:max_requests]:
+ if s < min_seconds:
+ continue
+ if label:
+ print label
+ label = ''
+ if not printed:
+ minutes_footer_html()
+ print '<table border="1">'
+ print '<tr><th>age</th><th>R</th><th>url</th><th>state</th></tr>'
+ printed = True
+ url = request.url
+ repeat = urls[url]
+ print '<tr>'
+ if repeat <= 1:
+ repeat = ''
+ url = '<a href="#u%s">%s</a>' % (allurls[url].tid, url)
+ print td(s, repeat, url, request.state)
+ print '</tr>'
+
+ if printed:
+ print '</table>'
+ minutes_header_html()
+
+parser = optparse.OptionParser("""
+Usage: %prog [options] trace_log_file
+
+Output trace log data showing:
+
+- 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.
+
+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.
+
+Also, note that, unfortunately, application requests include requests
+that are running in application threads and requests waiting to get an
+application thread.
+
+When application threads get above the app request threshold, then we
+show the requests that have been waiting the longest.
+
+""")
+
+parser.add_option("--app-request-threshold", "-a", dest='apps',
+ type="int", default=10,
+ help="""
+Number of pending application requests at which detailed request information
+if printed.
+""")
+parser.add_option("--app-requests", "-r", dest='app_requests',
+ type="int", default=10,
+ help="""
+How many requests to show when the maximum number of pending
+apps is exceeded.
+""")
+parser.add_option("--old-requests", "-o", dest='old_requests',
+ type="int", default=10,
+ help="""
+Number of seconds beyond which a request is considered old.
+""")
+parser.add_option("--event-log", "-e", dest='event_log',
+ help="""
+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.
+""")
+parser.add_option("--html", dest='html', action='store_true',
+ help="""
+Generate HTML output.
+""")
+parser.add_option("--remove-prefix", dest='remove_prefix',
+ help="""
+A prefex to be removed from URLS.
+""")
+
+
+
+if __name__ == '__main__':
+ main()
Property changes on: zc.zservertracelog/branches/dev/src/zc/zservertracelog/tracereport.py
___________________________________________________________________
Name: svn:keywords
+ Id
Name: svn:eol-style
+ native
More information about the Checkins
mailing list