launchpad-reviewers team mailing list archive

[Robert Collins <robertc@xxxxxxxxxxxxxxxxx>]

Robert Collins has proposed merging lp:~lifeless/python-oops-tools/polish into lp:python-oops-tools.

Requested reviews:
  Launchpad code reviewers (launchpad-reviewers)
Related bugs:
  Bug #890976 in python-oops-tools: "hard to determine causes of late evaluation"
  https://bugs.launchpad.net/python-oops-tools/+bug/890976

For more details, see:
https://code.launchpad.net/~lifeless/python-oops-tools/polish/+merge/82365

Update the oops-tools model to show the new backtrace column in OOPS report timelines.

This is a bit crude - I'm making a somewhat horrid table more horrid (by making it wider). It also makes simple queries have a big gap between them.

OTOH there is a bit of a steep curve to get a js library in here due to our preferred tech not being the default in Django. I think we'll have a net benefit from this change without nice JS hiding, and I'm going to investigate JS hiding separately - e.g. Talk to francis about ROI, preferred choice etc etc.

This change can be easily backed out (its about 5 minutes to go from intent to deployed on our oops-tools instance a the moment) if we decide its a problem, so I'd like to get it up there and see.

Most of the changes have test coverage (in that tests broke when the change was made) except the actual template change itself. I've added a smoke test there (that the heading exists, which implies something about the body of the table), but its not truely satisfactory. OTOH I don't know what would be really satisfactory, given we're dealing with a pagetest here.

Thanks for your consideration :)
-- 
https://code.launchpad.net/~lifeless/python-oops-tools/polish/+merge/82365
Your team Launchpad code reviewers is requested to review the proposed merge of lp:~lifeless/python-oops-tools/polish into lp:python-oops-tools.

=== modified file 'src/oopstools/NEWS.txt'
--- src/oopstools/NEWS.txt	2011-11-16 02:22:14 +0000
+++ src/oopstools/NEWS.txt	2011-11-16 08:16:24 +0000
@@ -22,6 +22,11 @@
   a bit better.
   (Robert Collins, William Grant, Roman Yepishev, #885416, #884265)
 
+* Report timelines now include a backtrace for each event, making it easier to
+  determine the origin of the event (e.g. why something is looked up).
+  Timelines without this information will show 'unknown' in the relevant
+  column on the OOPS page. (Robert Collins, #890976)
+
 * The req_vars variable in OOPS reports may now be a dict.
   (Robert Collins, #888866)
 

=== modified file 'src/oopstools/oops/models.py'
--- src/oopstools/oops/models.py	2011-11-16 07:25:56 +0000
+++ src/oopstools/oops/models.py	2011-11-16 08:16:24 +0000
@@ -350,11 +350,11 @@
     # Sanity check/coerce the statements into what we expect.
     # Must be a list:
     if not isinstance(statements, list):
-        statements = [(0, 0, 'badtimeline', str(statements))]
+        statements = [(0, 0, 'badtimeline', str(statements), 'unknown')]
     else:
-        filler = (0, 0, 'unknown', 'unknown')
+        filler = (0, 0, 'unknown', 'unknown', 'unknown')
         for row, action in enumerate(statements):
-            statements[row] = tuple(action[:4]) + filler[len(action):]
+            statements[row] = tuple(action[:5]) + filler[len(action):]
     duration = oops.get('duration')
     if duration is not None:
         total_time = int(duration * 1000)
@@ -388,7 +388,7 @@
         most_expensive_statement = None
     else:
         costs = {}
-        for (start, end, db_id, statement) in statements:
+        for (start, end, db_id, statement, tb) in statements:
             statement = replace_variables(statement)
             cost = end - start
             if statement in costs:
@@ -566,8 +566,8 @@
         #XXX need docstring and test
         if not self.statements:
             return []
-        return [(count+1, start, stop, db_id, stop - start, stmt) for
-                (count, (start, stop, db_id, stmt)) in
+        return [(count+1, start, stop, db_id, stop - start, stmt, tb) for
+                (count, (start, stop, db_id, stmt, tb)) in
                 enumerate(self.statements)]
 
     def repeated_statements(self):
@@ -623,7 +623,7 @@
         if not self.statements:
             return 0
         accumulated_time = 0
-        for (start, stop, db_id, stmt) in self.statements:
+        for (start, stop, db_id, stmt, trace) in self.statements:
             length = stop - start
             accumulated_time += length
         return accumulated_time
@@ -636,13 +636,13 @@
     def _group_queries(self, unsorted_statements):
         """Group SQL log queries.
 
-        unsorted_statements is a list of (start, stop, db_id, statement).
+        unsorted_statements is a list of (start, stop, db_id, statement, tb).
         Return a list of (total_time_ms, count, mean_length, saving, db_id,
         statement).
         """
         sorted_statements = sorted(
             unsorted_statements,
-            key=lambda (start, stop, db_id, statement): statement
+            key=lambda row: row[3]
             )
         groups = []
         def append_to_group(gtime, gcount, db_id, statement):
@@ -653,7 +653,7 @@
 
         group_statement = None
         for row in sorted_statements:
-            start, stop, db_id, statement = row
+            start, stop, db_id, statement, tb = row
             statement = replace_variables(statement)
             length = stop - start
             if statement != group_statement:

=== modified file 'src/oopstools/oops/templates/oops.html'
--- src/oopstools/oops/templates/oops.html	2011-10-13 20:18:51 +0000
+++ src/oopstools/oops/templates/oops.html	2011-11-16 08:16:24 +0000
@@ -168,16 +168,18 @@
          <th>Length</th>
          <th>Database id</th>
          <th>Statement</th>
+         <th>Traceback</th>
        </tr>
      </thead>
      <tbody>
-       {% for num, start, stop, db_id, length, statement in oops.formatted_statements %}
+       {% for num, start, stop, db_id, length, statement, tb in oops.formatted_statements %}
          <tr>
            <td>{{num}}.</td>
            <td>{{start}}</td>
            <td>{{length}}ms</td>
            <td>{{db_id}}</td>
            <td><pre>{{statement|format_sql}}</pre></td>
+           <td><pre>{{tb}}</pre></td>
          </tr>
       {% endfor %}
      </tbody>

=== modified file 'src/oopstools/oops/test/oops.txt'
--- src/oopstools/oops/test/oops.txt	2011-11-02 21:29:36 +0000
+++ src/oopstools/oops/test/oops.txt	2011-11-16 08:16:24 +0000
@@ -263,7 +263,7 @@
 recorded together with the SQL statement.
 
     >>> oops_with_db_id = Oops.objects.get(oopsid__exact="OOPS-1308x1")
-    >>> for start, stop, db_id, statement in oops_with_db_id.statements:
+    >>> for start, stop, db_id, statement, tb in oops_with_db_id.statements:
     ...     print start, stop, db_id, statement
     4 5 session UPDATE SessionData SET last_accessed ...
     6 7 session SELECT key, pickle FROM SessionPkgData WHERE ...

=== modified file 'src/oopstools/oops/test/pagetest.txt'
--- src/oopstools/oops/test/pagetest.txt	2011-11-02 23:26:40 +0000
+++ src/oopstools/oops/test/pagetest.txt	2011-11-16 08:16:24 +0000
@@ -38,7 +38,8 @@
     ...<div id="request_variables">...
     ...
     ...<li>CHANNEL_CREATION_TIME: 1...</li>...
-    ...
+    ...SQL Statement Log...
+    ...Start...Length...Database id...Statement...Traceback...
 
 It also accepts the OOPS id without the "OOPS-" part.
 

=== modified file 'src/oopstools/oops/test/test_dboopsloader.py'
--- src/oopstools/oops/test/test_dboopsloader.py	2011-11-16 02:22:14 +0000
+++ src/oopstools/oops/test/test_dboopsloader.py	2011-11-16 08:16:24 +0000
@@ -196,7 +196,8 @@
             'timeline': 'a'
         }
         oops = parsed_oops_to_model_oops(report, 'bug-890001-1')
-        self.assertEqual([(0, 0, 'badtimeline', 'a')], oops.statements)
+        self.assertEqual(
+            [(0, 0, 'badtimeline', 'a', 'unknown')], oops.statements)
         
     def test_short_timeline_row(self):
         # A timeline row that is short is padded with 'unknown' or 0's.
@@ -211,10 +212,10 @@
         }
         oops = parsed_oops_to_model_oops(report, 'bug-890001-2')
         self.assertEqual([
-            (0, 0, 'unknown', 'unknown'),
-            (1, 0, 'unknown', 'unknown'),
-            (1, 2, 'unknown', 'unknown'),
-            (1, 2, 'foo', 'unknown'),
+            (0, 0, 'unknown', 'unknown', 'unknown'),
+            (1, 0, 'unknown', 'unknown', 'unknown'),
+            (1, 2, 'unknown', 'unknown', 'unknown'),
+            (1, 2, 'foo', 'unknown', 'unknown'),
             ], oops.statements)
 
     def test_long_timeline_row(self):
@@ -222,12 +223,12 @@
         report = {
             'id': 'bug-890001-3',
             'timeline': [
-                (1, 2, 'foo', 'bar', 'baz'),
+                (1, 2, 'foo', 'bar', 'baz', 'quux'),
                 ],
         }
         oops = parsed_oops_to_model_oops(report, 'bug-890001-3')
         self.assertEqual([
-            (1, 2, 'foo', 'bar'),
+            (1, 2, 'foo', 'bar', 'baz'),
             ], oops.statements)
 
     def test_empty_report_long_id_uses_unknown_bug_889982(self):