Always display the start and end date of the request

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,22 +79,25 @@ 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::
 
     Entry position                       Called path
          |                                   |
          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
 =======

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)
 ----------------

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'],