Merge lp:~jcsackett/launchpad/hardwaredb-should-ignore-bad-data into lp:launchpad

[j.c.sackett]

[r=danilo][bug=676988,747532] Disables oops creation for hardware processing errors introduced by bad data we do not control.

Summary
=======

Bad data sent to the HWDB caused an OOPS when it failed to validate. While we want to log the bad data as an error, we don't want it to generate an OOPS and get in the OOPS report, because there's nothing we can do about it beyond report bad data coming in from another source.

Preimplementation
=================

Spoke with Curtis Hovey, and explored the problem with him.

Implementation
==============
lib/lp/services/scripts/base.py
-------------------------------
Added a contextmanager for the OopsHandler that temporarily removes it from a logger, and adds it back in after the context expires.

lib/lp/hardwaredb/scripts/hwdbsubmissions.py
--------------------------------------------
Updated the self._logError method for the script to take a parameter indicating whether or not an Oops should be created. The contextmanager created in base.py is used to disable the Oopshandler if the parameter is false. It defaults to true.

lib/canonical/launchpad/scripts/tests/baddatahardwaretest.xml
lib/lp/hardwaredb/tests/test_hwdb_submission_validation.py
----------------------------------------------------------
Tests and test data.

Tests
=====

bin/test -vvct test_hwdb

QA
==

Create a hardware db entry on qastaging, staging, or launchpad.dev, using bad data (the data from the bug's linked oops report would be fine). Fire of the process-hwdb-submission job and confirm that no oops report is created for the bad data you provided.

Lint
====

= Launchpad lint =

Checking for conflicts and issues in changed files.

Linting changed files:
  lib/canonical/launchpad/scripts/tests/baddatahardwaretest.xml
  lib/lp/hardwaredb/scripts/hwdbsubmissions.py
  lib/lp/hardwaredb/tests/test_hwdb_submission_validation.py
  lib/lp/services/scripts/base.py

[Данило Шеган (danilo)]

As discussed on IRC, I dislike having a big XML file in the code with no clear indication what exactly is it about (other than being "bad" :), so you agreed: "in order, i'll try: modifying the data on the fly; cleaning everything possible out of the file; adding a big comment."

Regarding the XXX and cElementTree import in lib/lp/hardwaredb/scripts/hwdbsubmissions.py, JFDI is my suggestion.

Also, it'd be nice to have a minimal test for context-manager disable_oops_handler just so nobody breaks it for you.

review: Approve

=== modified file 'lib/lp/hardwaredb/scripts/hwdbsubmissions.py'
--- lib/lp/hardwaredb/scripts/hwdbsubmissions.py	2010-08-24 10:36:30 +0000
+++ lib/lp/hardwaredb/scripts/hwdbsubmissions.py	2011-04-08 19:03:55 +0000
@@ -13,11 +13,11 @@
            'process_pending_submissions',
           ]
 
-
 import bz2
 from cStringIO import StringIO
 
-
+#XXX: Given the version of python we know we're running on now,
+# is the try/except here necessary?
 try:
     import xml.etree.cElementTree as etree
 except ImportError:
@@ -39,14 +39,24 @@
 from canonical.config import config
 from canonical.librarian.interfaces import LibrarianServerError
 from lp.hardwaredb.interfaces.hwdb import (
-    HWBus, HWSubmissionProcessingStatus, IHWDeviceDriverLinkSet, IHWDeviceSet,
-    IHWDriverSet, IHWSubmissionDeviceSet, IHWSubmissionSet, IHWVendorIDSet,
-    IHWVendorNameSet)
+    HWBus,
+    HWSubmissionProcessingStatus,
+    IHWDeviceDriverLinkSet,
+    IHWDeviceSet,
+    IHWDriverSet,
+    IHWSubmissionDeviceSet,
+    IHWSubmissionSet,
+    IHWVendorIDSet,
+    IHWVendorNameSet,
+    )
 from canonical.launchpad.interfaces.launchpad import ILaunchpadCelebrities
 from canonical.launchpad.interfaces.looptuner import ITunableLoop
 from canonical.launchpad.utilities.looptuner import LoopTuner
 from canonical.launchpad.webapp.errorlog import (
-    ErrorReportingUtility, ScriptRequest)
+    ErrorReportingUtility,
+    ScriptRequest,
+    )
+from lp.services.scripts.base import disable_oops_handler
 
 _relax_ng_files = {
     '1.0': 'hardware-1_0.rng', }
@@ -126,10 +136,14 @@
         self._setHardwareSectionParsers()
         self._setSoftwareSectionParsers()
 
-    def _logError(self, message, submission_key):
+    def _logError(self, message, submission_key, create_oops=True):
         """Log `message` for an error in submission submission_key`."""
-        self.logger.error(
-            'Parsing submission %s: %s' % (submission_key, message))
+        msg = 'Parsing submission %s: %s' % (submission_key, message)
+        if not create_oops:
+            with disable_oops_handler(self.logger):
+                self.logger.error(msg)
+        else:
+            self.logger.error(msg)
 
     def _logWarning(self, message, warning_id=None):
         """Log `message` for a warning in submission submission_key`."""
@@ -172,7 +186,8 @@
         if not validator.validate(submission):
             self._logError(
                 'Relax NG validation failed.\n%s' % validator.error_log,
-                submission_key)
+                submission_key,
+                create_oops=False)
             return None
         return submission_doc
 

=== removed directory 'lib/lp/hardwaredb/scripts/tests'
=== renamed file 'lib/lp/hardwaredb/scripts/tests/real_hwdb_submission.xml.bz2' => 'lib/lp/hardwaredb/tests/real_hwdb_submission.xml.bz2'
=== renamed file 'lib/lp/hardwaredb/scripts/tests/test_hwdb_submission_validation.py' => 'lib/lp/hardwaredb/tests/test_hwdb_submission_validation.py'
--- lib/lp/hardwaredb/scripts/tests/test_hwdb_submission_validation.py	2010-10-04 19:50:45 +0000
+++ lib/lp/hardwaredb/tests/test_hwdb_submission_validation.py	2011-04-08 19:03:55 +0000
@@ -11,10 +11,11 @@
     TestCase,
     TestLoader,
     )
-
 from zope.testing.loghandler import Handler
 
 from canonical.config import config
+from canonical.launchpad.webapp.errorlog import globalErrorUtility
+from canonical.launchpad.scripts.logger import OopsHandler
 from canonical.testing.layers import BaseLayer
 from lp.hardwaredb.scripts.hwdbsubmissions import SubmissionParser
 
@@ -56,13 +57,15 @@
                                                                submission_id)
         return result, submission_id
 
-    def insertSampledata(self, data, insert_text, where):
+    def insertSampledata(self, data, insert_text, where, after=False):
         """Insert text into the sample data `data`.
 
         Insert the text `insert_text` before the first occurrence of
         `where` in `data`.
         """
         insert_position = data.find(where)
+        if after:
+            insert_position += len(where)
         return data[:insert_position] + insert_text + data[insert_position:]
 
     def replaceSampledata(self, data, replace_text, from_text, to_text):
@@ -99,6 +102,36 @@
         self.assertEqual(result, None,
                          'Invalid root node not detected')
 
+    def _getLastOopsTime(self):
+        try:
+            last_oops_time = globalErrorUtility.getLastOopsReport().time
+        except AttributeError:
+            # There haven't been any oopses in this test run
+            last_oops_time = None
+        return last_oops_time
+
+    def test_bad_data_does_not_oops(self):
+        # If the processing cronscript gets bad data, it should log it, but
+        # it should not create an Oops.
+        sample_data = self.insertSampledata(
+            data=self.sample_data,
+            insert_text=('<dmi>'
+                '/sys/class/dmi/id/bios_vendor:Dell Inc.'
+                '/sys/class/dmi/id/bios_version:A12'
+                '</dmi>'),
+            where = '<hardware>',
+            after=True)
+        # Add the OopsHandler to the log, because we want to make sure this
+        # doesn't create an Oops report.
+        logging.getLogger('test_hwdb_submission_parser').addHandler(OopsHandler(self.log.name))
+        result, submission_id = self.runValidator(sample_data)
+        last_oops_time = self._getLastOopsTime()
+        # We use the class method here, because it's been overrided for the
+        # other tests in this test case.
+        TestCase.assertEqual(self,
+            self._getLastOopsTime(),
+            last_oops_time)
+
     def testInvalidFormatVersion(self):
         """The attribute `format` of the root node must be `1.0`."""
         sample_data = '<?xml version="1.0" ?><system version="nonsense"/>'

=== modified file 'lib/lp/services/scripts/base.py'
--- lib/lp/services/scripts/base.py	2011-03-30 16:39:06 +0000
+++ lib/lp/services/scripts/base.py	2011-04-08 19:03:55 +0000
@@ -6,9 +6,11 @@
     'LaunchpadCronScript',
     'LaunchpadScript',
     'LaunchpadScriptFailure',
+    'disable_oops_handler',
     'SilentLaunchpadScriptFailure',
     ]
 
+from contextlib import contextmanager
 from ConfigParser import SafeConfigParser
 from cProfile import Profile
 import datetime
@@ -401,6 +403,17 @@
             date_completed=date_completed)
         self.txn.commit()
 
+@contextmanager
+def disable_oops_handler(logger):
+    oops_handlers = []
+    for handler in logger.handlers:
+        if isinstance(handler, OopsHandler):
+            oops_handlers.append(handler)
+            logger.removeHandler(handler)
+    yield
+    for handler in oops_handlers:
+        logger.addHandler(handler)
+
 
 def cronscript_enabled(control_url, name, log):
     """Return True if the cronscript is enabled."""