launchpad-reviewers team mailing list archive

[William Grant <me@xxxxxxxxxxxxxxxxxx>]

William Grant has proposed merging lp:~wgrant/launchpad/suppress-updatebugwatches-errors into lp:launchpad.

Requested reviews:
  Launchpad code reviewers (launchpad-reviewers)
Related bugs:
  #716421 BugTrackerAuthenticationError: 401 "Unauthorized"
  https://bugs.launchpad.net/bugs/716421
  #728820 BugWatchUpdateErrors in updateBugWatches should not OOPS
  https://bugs.launchpad.net/bugs/728820

For more details, see:
https://code.launchpad.net/~wgrant/launchpad/suppress-updatebugwatches-errors/+merge/52794

This branch fixes lots of checkwatches errors. BugWatchUpdateErrors and socket.timeouts from inside updateBugWatches no longer OOPS: they get logged at info instead (they are already logged in BugWatchActivity).

updateBugWatches also had an unchecked getCurrentDBTime call, causing errors like OOPS-1866CCW1292 to not be logged in BugWatchActivity. I've extracted the except-bulkSetError-raise pattern into a context manager, and wrapped getCurrentDBTime in it.

Test changes are minimal... it's difficult to get write sane ones until all current exceptions are handled and we can look at error handling throughout checkwatches as a whole.
-- 
https://code.launchpad.net/~wgrant/launchpad/suppress-updatebugwatches-errors/+merge/52794
Your team Launchpad code reviewers is requested to review the proposed merge of lp:~wgrant/launchpad/suppress-updatebugwatches-errors into lp:launchpad.

=== modified file 'lib/lp/bugs/doc/checkwatches.txt'
--- lib/lp/bugs/doc/checkwatches.txt	2011-03-09 23:51:44 +0000
+++ lib/lp/bugs/doc/checkwatches.txt	2011-03-10 03:11:21 +0000
@@ -137,9 +137,8 @@
 
 Next, we monkey-patch urllib2.urlopen so that it always times out.
 
-The timeout will also produce an OOPS report and the OOPS id will be
-included in the logged error message. The URL field of the OOPS report
-will also be automatically filled from the baseurl OOPS property.
+The timeout will not produce an OOPS report; they happen routinely and
+require no action from the Launchpad end.
 
     >>> import socket
     >>> import urllib2
@@ -157,28 +156,9 @@
     ...     urllib2.urlopen = urlopen
     >>> dump_last_oops()
     Oops-Id: OOPS-...TCW...
-    Exception-Type: timeout
-    Exception-Value: Connection timed out.
-    Date: ...
-    Page-Id:
-    Branch: ...
-    Revision: ...
-    User: None
-    URL: http://bugs.example.com
-    Duration: ...
-    Informational: False
-    <BLANKLINE>
-    baseurl=http://bugs.example.com
-    bugtracker=example-bugs
-    error-explanation=Connection timed out ... http://bugs.example.com
-    <BLANKLINE>
-    ...SELECT COUNT(*) FROM...
-    ...SELECT BugTracker.active, BugTracker.baseurl...
-    ...Transaction completed, status: Committed...
-    <BLANKLINE>
-    Traceback (most recent call last):
+    Exception-Type: BugWatchUpdateWarning
+    Exception-Value: ExternalBugtracker for BugTrackerType 'SAVANE' ...
     ...
-    timeout: Connection timed out.
 
 Errors that occur when updating a bug watch are recorded against that
 bug watch. The timeout will be recorded against the bug watch we just

=== modified file 'lib/lp/bugs/scripts/checkwatches/core.py'
--- lib/lp/bugs/scripts/checkwatches/core.py	2011-03-01 02:25:29 +0000
+++ lib/lp/bugs/scripts/checkwatches/core.py	2011-03-10 03:11:21 +0000
@@ -14,6 +14,7 @@
     'externalbugtracker',
     ]
 
+from contextlib import contextmanager
 from copy import copy
 from datetime import (
     datetime,
@@ -190,6 +191,25 @@
                         "Updates are disabled for bug tracker at %s" %
                         bug_tracker_baseurl)
 
+    @contextmanager
+    def record_errors(self, bug_watch_ids):
+        """Context manager to record errors in BugWatchActivity.
+
+        If an exception occurs, it will be logged in BugWatchActivity
+        against all the given watches.
+        """
+        try:
+            yield
+        except Exception, e:
+            # We record the error against all the bugwatches that should
+            # have been updated before re-raising it. We also update the
+            # bug watches' lastchecked dates so that checkwatches
+            # doesn't keep trying to update them every time it runs.
+            with self.transaction:
+                getUtility(IBugWatchSet).bulkSetError(
+                    bug_watch_ids, get_bugwatcherrortype_for_error(e))
+            raise
+
     @commit_before
     def updateBugTrackers(
         self, bug_tracker_names=None, batch_size=None, scheduler=None):
@@ -251,19 +271,20 @@
             # If something unexpected goes wrong, we log it and
             # continue: a failure shouldn't break the updating of
             # the other bug trackers.
-            info = sys.exc_info()
-            properties = [
-                ('bugtracker', bug_tracker_name),
-                ('baseurl', bug_tracker_url)]
             if isinstance(error, BugWatchUpdateError):
-                self.error(
-                    str(error), properties=properties, info=info)
+                self.logger.info(
+                    "Error updating %s: %s" % (
+                        bug_tracker.baseurl, error))
             elif isinstance(error, socket.timeout):
-                self.error(
-                    "Connection timed out when updating %s" %
-                    bug_tracker_url,
-                    properties=properties, info=info)
+                self.logger.info(
+                    "Connection timed out when updating %s" % (
+                        bug_tracker.baseurl))
             else:
+                # Unknown exceptions are logged as OOPSes.
+                info = sys.exc_info()
+                properties = [
+                    ('bugtracker', bug_tracker_name),
+                    ('baseurl', bug_tracker_url)]
                 self.error(
                     "An exception was raised when updating %s" %
                     bug_tracker_url,
@@ -576,17 +597,10 @@
         # Fetch the time on the server. We'll use this in
         # _getRemoteIdsToCheck() and when determining whether we can
         # sync comments or not.
-        server_time = remotesystem.getCurrentDBTime()
-        try:
+        with self.record_errors(bug_watch_ids):
+            server_time = remotesystem.getCurrentDBTime()
             remote_ids = self._getRemoteIdsToCheck(
                 remotesystem, bug_watches, server_time, now, batch_size)
-        except TooMuchTimeSkew, error:
-            # If there's too much time skew we can't continue with this
-            # run.
-            with self.transaction:
-                getUtility(IBugWatchSet).bulkSetError(
-                    bug_watch_ids, get_bugwatcherrortype_for_error(error))
-            raise
 
         remote_ids_to_check = remote_ids['remote_ids_to_check']
         all_remote_ids = remote_ids['all_remote_ids']
@@ -604,17 +618,8 @@
             "Updating %i watches for %i bugs on %s" % (
                 len(bug_watches), len(remote_ids_to_check), bug_tracker_url))
 
-        try:
+        with self.record_errors(bug_watch_ids):
             remotesystem.initializeRemoteBugDB(remote_ids_to_check)
-        except Exception, error:
-            # We record the error against all the bugwatches that should
-            # have been updated before re-raising it. We also update the
-            # bug watches' lastchecked dates so that checkwatches
-            # doesn't keep trying to update them every time it runs.
-            with self.transaction:
-                getUtility(IBugWatchSet).bulkSetError(
-                    bug_watch_ids, get_bugwatcherrortype_for_error(error))
-            raise
 
         for remote_bug_id in all_remote_ids:
             remote_bug_updater = self.remote_bug_updater_factory(