From 226c5177bc833e3d293f3691c3efd6fbb0b8e4df Mon Sep 17 00:00:00 2001 From: Luca Fabbri Date: Thu, 15 Nov 2012 12:18:05 +0100 Subject: [PATCH] Always display the start and end date of the request --- README.rst | 37 ++++++++++++++++++++----------------- docs/HISTORY.txt | 5 +++-- src/zope_lrr_analyzer.py | 14 +++++++++++--- 3 files changed, 34 insertions(+), 22 deletions(-) diff --git a/README.rst b/README.rst index d9d6408..e6969fd 100644 --- a/README.rst +++ b/README.rst @@ -42,15 +42,15 @@ Results Let's explain the results:: - Stats from 2012-04-27 00:02:07 to 2012-04-27 16:55:41 + Stats from 2012-11-14 00:02:07 to 2012-11-15 09:55:41 ... - ---- - 2 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/foo/foo - 15 - 171.913325071 (0:02:51.913325) - ---- - 1 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/foo/another - 3 - 1350.58498883 (0:22:30.584989) + 2 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/foo/bar + 25 - 3654.05561542 (1:00:54.055615) - from 2012-11-15 07:48:10 to 2012-11-15 08:45:29 + + ---- + 1 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/baz + 77 - 16029.3731236 (4:27:09.373124) - from 2012-11-15 07:43:55 to 2012-11-15 08:45:30 You'll get a rank of slowest request paths (top one is fastest, last one is slowest). The order is done by collecting all request's performed to the same path and then getting the total time. @@ -64,11 +64,11 @@ so the output change a little:: Stats from 2012-04-27 00:02:07 to 2012-04-27 16:55:41 ... ---- - 2 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/foo/foo + 2 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/foo/bar 1510.2860291 (0:25:10.286029) - from 2012-09-19 08:36:27 to 2012-09-19 09:01:22 ---- - 1 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/foo/another + 1 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/baz 1750.49365091 (0:29:10.493651) - from 2012-09-19 08:30:34 to 2012-09-19 09:00:58 Single entry meaning @@ -79,11 +79,11 @@ Every entry gives that kind of data:: Entry position Called path | | 1 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/... - 15 - 171.913325071 (0:02:51.913325) - | | | - Times called | Time needed (human readable) - | - Time needed (in seconds) + 15 - 171.913325071 (0:02:51.913325) - from 2012-09-19 08:30:34 to 2012-09-19 09:00:58 + | | | | | + Times called | Time needed (human readable) | | + | | Slow request end date + Time needed (in seconds) Slow request start date When ``--keep-request-id`` used:: @@ -91,10 +91,13 @@ When ``--keep-request-id`` used:: | | 1 /VirtualHostBase/http/yoursite.com:80/siteid/VirtualHostRoot/... 1750.49365091 (0:29:10.493651) - from 2012-09-19 08:30:34 to 2012-09-19 09:00:58 - | | | | - Time needed (in seconds) | slow request start date | + | | | | + Time needed (in seconds) | Slow request start date | | | - Time needed (human readable) slow request end date + Time needed (human readable) Slow request end date + + +Please note that the "*Time needed*" info is machine computation time. Authors ======= diff --git a/docs/HISTORY.txt b/docs/HISTORY.txt index 0dcfaf8..356b8cc 100644 --- a/docs/HISTORY.txt +++ b/docs/HISTORY.txt @@ -4,8 +4,9 @@ Changelog 0.3 (unreleased) ---------------- -- Nothing changed yet. - +- Always display the start and end date of the request + (not only if ``-r`` option is given) + [keul] 0.2 (2012-09-19) ---------------- diff --git a/src/zope_lrr_analyzer.py b/src/zope_lrr_analyzer.py index 0c709c5..aaa2f84 100755 --- a/src/zope_lrr_analyzer.py +++ b/src/zope_lrr_analyzer.py @@ -27,7 +27,7 @@ except ImportError: from ordereddict import OrderedDict -version = "0.2" +version = "0.3" description = "Analyze Zope instance log with haufe.requestmonitoring entries" usage = "usage: %prog [options] logfile [logfile...]" @@ -144,9 +144,14 @@ def main(): unordered_stats[path]['totaltime'] = sum([float(x['reqtime']) for x in request_data]) unordered_stats[path]['req-thread-ids'] = tempstat.keys() if options.keep_req_id: + # every thread can keep start/end date unordered_stats[path]['start'] = request_data[0]['start'] unordered_stats[path]['end'] = request_data[0]['end'] - + else: + # we must store start/end date per request, ignoring thread + unordered_stats[path]['start'] = min([x['start'] for x in request_data]) + unordered_stats[path]['end'] = max([x['end'] for x in request_data]) + ### Step 3. final results final_stats = OrderedDict(sorted(unordered_stats.items(), key=lambda t: float(t[1]['totaltime']))) @@ -158,7 +163,10 @@ def main(): cnt = len(logset) for k,v in logset: if not options.keep_req_id: - print "----\n%s %s\n %d - %s (%s)\n" % (cnt, k, v['count'], v['totaltime'], timedelta(seconds=float(v['totaltime']))) + print "----\n%s %s\n %d - %s (%s) - from %s to %s\n" % (cnt, k, v['count'], v['totaltime'], + timedelta(seconds=float(v['totaltime'])), + v['start'], v['end'], + ) else: path, reqid, threadid = k.split('|') print "----\n%s %s (request %s/thread %s)\n %s (%s) - from %s to %s\n" % (cnt, path, reqid, threadid, v['totaltime'],