Merge lp:~jtv/launchpad/bug-436426-2 into lp:launchpad

[Jeroen T. Vermeulen]

[Jeroen T. Vermeulen (jtv)]

= Bug 436426 =

Bug 436426 says the translations importer should check approved queue
entries for certain inconsistencies. It would have spared us some
serious trouble if we'd done this before the 3.0 rollout.

With apologies, a branch squeezing only just under the review limit at
798 lines. It combines a bunch of improvements to the translations
importer with the actual bug fix:

 * Enables oops logging.

 * Makes the script class inherit straight from LaunchpadCronScript.

 * Refactors the script body to be much clearer.

 * Replaces assertions with more appropriate error handling.

 * Reports potentially repetitive errors in bulk.

 * Stops re-fetching the import targets list for every iteration.

 * Carries less state along in the doctest by clearing the queue.

A fair amount of diff is actually deletions from code that has moved
into better places. None of the changes in itself is particularly big;
it's just a big pile of cleanups that we'd never have gotten to without
an excuse.

== Detailed description ==

In configs, some configuration is needed for the oops logging. We'll
have to see that this actually works in production environments; recent
experience with the Job infrastructure shows that oops logging can go
horribly wrong if the configuration isn't right, and with no way to
alert developers, nor a way to test since the tests run on a separate
configuration.

In cronscripts: The script class in lp.translations.scripts, renamed
from ImportProcess to TranslationsImporter, now inherits directly from
LaunchpadCronScript. This removes an extra layer of inheritance in the
main script.

In doc/poimport.txt: the test runs now fire off LaunchpadCronScripts, so
the debug messages it logs on startup and shutdown show up in the test
output.

In doc/translationimportqueue.txt, you'll see how shamelessly we carried
state along the doctest. Made it almost impossible to change anything
except at the very end: every part of the test relied on the byproducts
of everything else before it. I've added a function to clear the queue.

Some errors that used to be reported as assertion failures are now kept
in a "failures" dict inside the script, and reported as oopses at the
end. They are also reported instantly, but for oops reporting, they are
bundled by error message. The idea is that an error affecting 4,600
entries gets oopsed once per script run, but with full details--as
opposed to producing 4,600 individual oopses.

Now we get to the actual script class. The time goal is no longer a
number of seconds living in a global variable; since everything from the
main script has moved in here, it's now a timedelta living in a member.

The failures are aggregated in a dict mapping a failure reason to lists
of queue entries that failed for that reason. That dict is initialized
not in main but in a constructor. This is done so that the unit tests
can exercise it realistically without invoking main. Regular syntax
errors and such are not kept here, but anything that shouldn't be fatal
to the script run yet isn't really expected is.

When you see the identifier "have_work," you're at the place where I
made an unrelated change. The script worked ...

[Edwin Grubbs (edwin-grubbs)]

Hi Jeroen,

This looks like a nice refactoring. I only have very minor suggestions.

merge-conditional

-Edwin

>=== modified file 'lib/lp/translations/doc/translationimportqueue.txt'
>--- lib/lp/translations/doc/translationimportqueue.txt 2009-09-25 15:40:58 +0000
>+++ lib/lp/translations/doc/translationimportqueue.txt 2009-09-30 19:25:02 +0000
>@@ -4,6 +4,14 @@
> into Rosetta.
>
> >>> from zope.security.proxy import removeSecurityProxy
>+ >>> from canonical.launchpad.interfaces.lpstorm import IStore
>+ >>> from lp.translations.model.translationimportqueue import (
>+ ... TranslationImportQueueEntry)
>+
>+ >>> def clear_queue(queue):
>+ ... """Remove all entries off the import queue."""
>+ ... store = IStore(TranslationImportQueueEntry)
>+ ... store.find(TranslationImportQueueEntry).remove()
>
>
> == getGuessedPOFile ==
>@@ -1296,6 +1304,15 @@
> If such bad requests do end up on the import queue, the import queue code will
> raise errors about them.
>
>+ >>> def print_import_failures(import_script):
>+ ... """List failures recorded in import script instance."""

Should that be singular with an article:
    "in an/the import script instance"
or plural without an article:
    "in import script instances"

>+ ... for reason, entries in script.failures.iteritems():
>+ ... print reason
>+ ... for entry in entries:
>+ ... print "-> " + entry
>+
>+ >>> clear_queue(translationimportqueue)
>+
> >>> entry = translationimportqueue.addOrUpdateEntry(
> ... u'po/sr.po', 'foo', True, rosetta_experts,
> ... productseries=evolution_productseries)
>@@ -1306,12 +1323,29 @@
> >>> entry.setStatus(RosettaImportStatus.APPROVED)
>
> >>> import logging
>- >>> from lp.translations.scripts.po_import import ImportProcess
>- >>> ImportProcess(transaction, logging).run()
>- Traceback (most recent call last):
>- ...
>- AssertionError: Broken translation import queue entry 4 (for evolution):
>- ...
>+ >>> from canonical.launchpad.scripts import FakeLogger
>+ >>> from lp.translations.scripts.po_import import TranslationsImport
>+
>+ >>> script = TranslationsImport('poimport', test_args=[])
>+ >>> script.logger = FakeLogger()
>+ >>> script.main()
>+ DEBUG Starting...
>+ ERROR Entry is approved but has no place to import to.
>+ ...
>+ DEBUG Finished the import process.
>+
>+ >>> print_import_failures(script)
>+ Entry is approved but has no place to import to.
>+ -> 'po/sr.po' (id ...) in Evolution trunk series
>+
>+The entry is marked as Failed.
>+
>+ >>> print entry.status.name
>+ FAILED
>+
>+This happens for distribution packages as well as products.
>+
>+ >>> clear_queue(translationimportqueue)
>
> >>> entry = translationimportqueue.addOrUpdateEntry(
> ... u'po/th.po', 'bar', False, rosetta_experts,
>@@ -1323,25 +1357,21 @@
>
> >>> entry.setStatus(RosettaImportStatus.APPROVED)
>
>- >>> ImportProcess(transaction, logging).run()
>- Traceback (most recent call last):
>- ...
>- AssertionError: Broken translation import queue entry 4 (for evolution):
>-...

review: Approve (code)

[Jeroen T. Vermeulen (jtv)]

Thanks for the review. Your remarks were:

> >=== modified file 'lib/lp/translations/doc/translationimportqueue.txt'
> >--- lib/lp/translations/doc/translationimportqueue.txt 2009-09-25 15:40:58
> +0000
> >+++ lib/lp/translations/doc/translationimportqueue.txt 2009-09-30 19:25:02
> +0000

> >@@ -1296,6 +1304,15 @@
> > If such bad requests do end up on the import queue, the import queue code
> will
> > raise errors about them.
> >
> >+ >>> def print_import_failures(import_script):
> >+ ... """List failures recorded in import script instance."""
>
> Should that be singular with an article:
> "in an/the import script instance"
> or plural without an article:
> "in import script instances"

"A." Added.

> >=== modified file 'lib/lp/translations/scripts/po_import.py'
> >--- lib/lp/translations/scripts/po_import.py 2009-09-18 07:39:51 +0000
> >+++ lib/lp/translations/scripts/po_import.py 2009-09-30 19:25:02 +0000

> >- def run(self):
> >- """Execute the import of entries from the queue."""
> >- # Get the queue.
> >+ # Time goal for one run. It is not exact. The script can run for
> >+ # longer than this, but will know to stop taking on new work.
> >+ # Since the script is run every 9 or 10 minutes, we set the "alarm"
>
>
> I would avoid calling this an alarm, since it makes me wonder if
> you are using signal.alarm(), even though you explain how it really
> works in the preceding sentence.

Okay, I changed it to say goal instead.

> >+ # at 8 minutes. That leaves a bit of time to complete the last
> >+ # ongoing batch of imports.
> >+ time_to_run = timedelta(minutes=8)
> >+
> >+ # Failures to be reported in bulk at closing, so we don't accumulate
> >+ # thousands of oopses for repetitive errors.
> >+ failures = None
>
>
> What is the purpose of initializing it here in addition to in the
> constructor? Is it used to create documentation that knows about
> instance variables?

Yes, just a place to comment it in really. Blame my background in static
languages.

> >+ self._reportFailures()
> >+
>
>
> Trailing white space.

Fixed. Thanks for spotting it.

Jeroen

review: Abstain

=== modified file 'configs/development/launchpad-lazr.conf'
--- configs/development/launchpad-lazr.conf	2009-09-28 11:12:51 +0000
+++ configs/development/launchpad-lazr.conf	2009-10-01 11:13:16 +0000
@@ -197,6 +197,10 @@
 error_dir: /var/tmp/rosettabranches.test
 oops_prefix: RSBR
 
+[poimport]
+error_dir: /var/tmp/poimport
+oops_prefix: POI
+
 [supermirror_puller]
 error_dir: /var/tmp/codehosting.test
 oops_prefix: SMP

=== modified file 'configs/testrunner/launchpad-lazr.conf'
--- configs/testrunner/launchpad-lazr.conf	2009-08-28 21:02:50 +0000
+++ configs/testrunner/launchpad-lazr.conf	2009-10-01 11:13:16 +0000
@@ -166,6 +166,10 @@
 [personalpackagearchive]
 root: /var/tmp/ppa.test/
 
+[poimport]
+error_dir: /var/tmp/poimport.test
+oops_prefix: TPOI
+
 [rosettabranches]
 oops_prefix: TRSBR
 error_dir: /var/tmp/rosettabranches.test

=== modified file 'cronscripts/rosetta-poimport.py'
--- cronscripts/rosetta-poimport.py	2009-07-17 00:26:05 +0000
+++ cronscripts/rosetta-poimport.py	2009-10-01 11:13:16 +0000
@@ -8,31 +8,9 @@
 import _pythonpath
 
 from canonical.config import config
-from canonical.database.sqlbase import ISOLATION_LEVEL_READ_COMMITTED
-from lp.translations.scripts.po_import import ImportProcess
-from lp.services.scripts.base import LaunchpadCronScript
-
-# Time goal for this run.  It is not exact.  The script will run for longer
-# than this time, but will know to stop taking on new batches of imports.
-# Since script is run every 9 or 10 minutes, we set the "alarm" at 8 minutes.
-# That leaves a bit of time to complete the last ongoing batch of imports.
-SECONDS_TO_RUN = 8 * 60
-
-class RosettaPOImporter(LaunchpadCronScript):
-    def main(self):
-        self.txn.set_isolation_level(ISOLATION_LEVEL_READ_COMMITTED)
-        process = ImportProcess(self.txn, self.logger, SECONDS_TO_RUN)
-        self.logger.debug('Starting the import process')
-        process.run()
-        self.logger.debug('Finished the import process')
-
+from lp.translations.scripts.po_import import TranslationsImport
 
 if __name__ == '__main__':
-    script = RosettaPOImporter('rosetta-poimport',
-        dbuser=config.poimport.dbuser)
-    script.lock_or_quit()
-    try:
-        script.run()
-    finally:
-        script.unlock()
-
+    script = TranslationsImport(
+        'rosetta-poimport', dbuser=config.poimport.dbuser)
+    script.lock_and_run()

=== modified file 'lib/canonical/config/schema-lazr.conf'
--- lib/canonical/config/schema-lazr.conf	2009-09-25 08:54:20 +0000
+++ lib/canonical/config/schema-lazr.conf	2009-10-01 11:13:16 +0000
@@ -1437,6 +1437,13 @@
 # Set to 'timeout' to make it timeout every time (for tests).
 statement_timeout: 300
 
+# See [error_reports].
+oops_prefix: none
+# See [error_reports].
+error_dir: none
+# See [error_reports].
+copy_to_zlog: false
+
 [processmail]
 # The database user which will be used by this process.
 # datatype: string
@@ -1538,7 +1545,6 @@
 # See [error_reports].
 copy_to_zlog: false
 
-
 [sendbranchmail]
 # The database user which will be used by this process.
 # datatype: string

=== modified file 'lib/canonical/launchpad/javascript/translations/translations.js'
--- lib/canonical/launchpad/javascript/translations/translations.js	2009-09-28 09:14:34 +0000
+++ lib/canonical/launchpad/javascript/translations/translations.js	2009-10-01 11:13:16 +0000
@@ -118,8 +118,10 @@
     var spinner_loader = Y.all('#spinner-loader');
     spinner_loader.set('innerHTML', '<img src="/@@/spinner" alt="" />');
     var button_markers = Y.all('.show-output');
-    button_markers.set('innerHTML', compose_button(false));
-    button_markers.attach('click', show_output);
+    if (button_markers) {
+        button_markers.set('innerHTML', compose_button(false));
+        button_markers.attach('click', show_output);
+    }
     // Remove the spinner again.
     spinner_loader.set('innerHTML', '');
 };

=== modified file 'lib/lp/translations/doc/poimport.txt'
--- lib/lp/translations/doc/poimport.txt	2009-09-21 19:31:07 +0000
+++ lib/lp/translations/doc/poimport.txt	2009-10-01 11:13:16 +0000
@@ -15,7 +15,7 @@
     ...     ITranslationImportQueue, RosettaImportStatus)
     >>> from lp.registry.model.sourcepackagename import SourcePackageName
     >>> from lp.translations.model.potemplate import POTemplateSubset
-    >>> from lp.translations.scripts.po_import import ImportProcess
+    >>> from lp.translations.scripts.po_import import TranslationsImport
     >>> from lp.translations.scripts.import_queue_gardener import (
     ...     ImportQueueGardener)
     >>> import datetime
@@ -644,12 +644,15 @@
 
     >>> import email
     >>> from lp.services.mail import stub
-    >>> process = ImportProcess(transaction, FakeLogger())
-    >>> process.run()
+    >>> process = TranslationsImport('poimport', test_args=[])
+    >>> process.logger = FakeLogger()
+    >>> process.main()
+    DEBUG   Starting the import process.
     INFO    Importing: Template "firefox" in Mozilla Firefox trunk
     INFO    Importing: Welsh (cy) ... of firefox in Mozilla Firefox trunk
     INFO    Importing: Welsh (cy) ... of firefox in Mozilla Firefox trunk
     INFO    Import requests completed.
+    DEBUG   Finished the import process.
 
 The import script also generates an email similar to the ones we saw
 composed before, but also sends it.
@@ -782,11 +785,14 @@
 Now that these submissions have been approved, the next run of the
 import script picks them up and processes them.
 
-    >>> process = ImportProcess(transaction, FakeLogger())
-    >>> process.run()
+    >>> process = TranslationsImport('poimport', test_args=[])
+    >>> process.logger = FakeLogger()
+    >>> process.main()
+    DEBUG   Starting the import process.
     INFO    Importing: Welsh (cy) ... of firefox in Mozilla Firefox trunk
     INFO    Importing: Welsh (cy) ... of firefox in Mozilla Firefox trunk
     INFO    Import requests completed.
+    DEBUG   Finished the import process.
 
     >>> print entry.status.name
     IMPORTED
@@ -866,8 +872,10 @@
 queue, but doesn't become a candidate for processing until warty
 imports are resumed.
 
-    >>> process = ImportProcess(transaction, FakeLogger())
-    >>> process.run()
+    >>> process = TranslationsImport('poimport', test_args=[])
+    >>> process.logger = FakeLogger()
+    >>> process.main()
+    DEBUG Starting the import process.
     INFO No requests pending.
 
     >>> print entry.status.name
@@ -1039,10 +1047,13 @@
 this, but is unable to.  This is unfortunate, but does not faze the
 importer.  It completes normally.
 
-    >>> process = ImportProcess(transaction, FakeLogger())
-    >>> process.run()
+    >>> process = TranslationsImport('poimport', test_args=[])
+    >>> process.logger = FakeLogger()
+    >>> process.main()
+    DEBUG Starting the import process.
     INFO Importing: Lao ...
     INFO Import requests completed.
+    DEBUG Finished the import process.
 
     >>> print entry.status.name
     FAILED

=== modified file 'lib/lp/translations/doc/translationimportqueue.txt'
--- lib/lp/translations/doc/translationimportqueue.txt	2009-09-25 15:40:58 +0000
+++ lib/lp/translations/doc/translationimportqueue.txt	2009-10-01 11:13:16 +0000
@@ -4,6 +4,14 @@
 into Rosetta.
 
     >>> from zope.security.proxy import removeSecurityProxy
+    >>> from canonical.launchpad.interfaces.lpstorm import IStore
+    >>> from lp.translations.model.translationimportqueue import (
+    ...     TranslationImportQueueEntry)
+
+    >>> def clear_queue(queue):
+    ...     """Remove all entries off the import queue."""
+    ...     store = IStore(TranslationImportQueueEntry)
+    ...     store.find(TranslationImportQueueEntry).remove()
 
 
 == getGuessedPOFile ==
@@ -1296,6 +1304,15 @@
 If such bad requests do end up on the import queue, the import queue code will
 raise errors about them.
 
+    >>> def print_import_failures(import_script):
+    ...     """List failures recorded in an import script instance."""
+    ...     for reason, entries in script.failures.iteritems():
+    ...         print reason
+    ...         for entry in entries:
+    ...             print "-> " + entry
+
+    >>> clear_queue(translationimportqueue)
+
     >>> entry = translationimportqueue.addOrUpdateEntry(
     ...     u'po/sr.po', 'foo', True, rosetta_experts,
     ...      productseries=evolution_productseries)
@@ -1306,12 +1323,29 @@
     >>> entry.setStatus(RosettaImportStatus.APPROVED)
 
     >>> import logging
-    >>> from lp.translations.scripts.po_import import ImportProcess
-    >>> ImportProcess(transaction, logging).run()
-    Traceback (most recent call last):
-    ...
-    AssertionError: Broken translation import queue entry 4 (for evolution):
-    ...
+    >>> from canonical.launchpad.scripts import FakeLogger
+    >>> from lp.translations.scripts.po_import import TranslationsImport
+
+    >>> script = TranslationsImport('poimport', test_args=[])
+    >>> script.logger = FakeLogger()
+    >>> script.main()
+    DEBUG Starting...
+    ERROR Entry is approved but has no place to import to.
+    ...
+    DEBUG Finished the import process.
+
+    >>> print_import_failures(script)
+    Entry is approved but has no place to import to.
+    -> 'po/sr.po' (id ...) in Evolution trunk series
+
+The entry is marked as Failed.
+
+    >>> print entry.status.name
+    FAILED
+
+This happens for distribution packages as well as products.
+
+    >>> clear_queue(translationimportqueue)
 
     >>> entry = translationimportqueue.addOrUpdateEntry(
     ...     u'po/th.po', 'bar', False, rosetta_experts,
@@ -1323,25 +1357,21 @@
 
     >>> entry.setStatus(RosettaImportStatus.APPROVED)
 
-    >>> ImportProcess(transaction, logging).run()
-    Traceback (most recent call last):
-    ...
-    AssertionError: Broken translation import queue entry 4 (for evolution):
-    ...
+    >>> script = TranslationsImport('poimport', test_args=[])
+    >>> script.logger.setLevel(logging.FATAL)
+    >>> script.main()
+    >>> print_import_failures(script)
+    Entry is approved but has no place to import to.
+    -> 'po/th.po' (id ...) in ubuntu Hoary package evolution
+
+    >>> print entry.status.name
+    FAILED
+
+    >>> clear_queue(translationimportqueue)
 
 
 == getRequestTargets output ordering ==
 
-TranslationImportQueue.getRequestTargets first lists distro series
-(ordered by distro name and series name), followed by products (ordered
-by name).
-
-    >>> print_list(get_target_names(RosettaImportStatus.APPROVED))
-    ubuntu/hoary    Hoary
-    evolution       Evolution
-    firefox         Mozilla Firefox
-
-
 The queue is populated with a wild mix of requests: for packages in
 different release series of Ubuntu, for packages in different distros,
 for product series, with different statuses; some were imported from
@@ -1388,29 +1418,24 @@
     >>> entry.setStatus(RosettaImportStatus.NEEDS_REVIEW)
     >>> flush_database_updates()
 
-
-The targets (distro series or products) that these requests are for are
-always listed in the same, predictable order.
+TranslationImportQueue.getRequestTargets first lists distro series
+(ordered by distro name and series name), followed by products (ordered
+by name).
 
     >>> print_list(get_target_names())
     debian/sarge        Sarge
     debian/woody        Woody
     kubuntu/krunch      Krunch
     ubuntu/grumpy       Grumpy
-    ubuntu/hoary        Hoary
     alsa-utils          alsa-utils
     evolution           Evolution
-    firefox             Mozilla Firefox
-    netapplet           NetApplet
 
     >>> for status in RosettaImportStatus.items:
     ...     print "%s:" % status.name
     ...     print_list(get_target_names(status))
     APPROVED:
     kubuntu/krunch      Krunch
-    ubuntu/hoary        Hoary
     evolution           Evolution
-    firefox             Mozilla Firefox
     IMPORTED:
     evolution           Evolution
     DELETED:
@@ -1419,13 +1444,15 @@
     NEEDS_REVIEW:
     debian/sarge        Sarge
     debian/woody        Woody
-    ubuntu/hoary        Hoary
-    evolution           Evolution
-    firefox             Mozilla Firefox
-    netapplet           NetApplet
     BLOCKED:
     ubuntu/grumpy       Grumpy
 
+You can also select by status.
+
+    >>> print_list(get_target_names(RosettaImportStatus.APPROVED))
+    kubuntu/krunch      Krunch
+    evolution           Evolution
+
 
 == cleanUpQueue ==
 

=== modified file 'lib/lp/translations/scripts/po_import.py'
--- lib/lp/translations/scripts/po_import.py	2009-09-18 07:39:51 +0000
+++ lib/lp/translations/scripts/po_import.py	2009-10-01 11:13:16 +0000
@@ -10,44 +10,135 @@
     'ImportProcess',
     ]
 
-import time
+from datetime import datetime, timedelta
+import sys
 
+from pytz import UTC
 from zope.component import getUtility
 
 from canonical.config import config
-from canonical.database.sqlbase import flush_database_updates
 from canonical.launchpad import helpers
 from canonical.launchpad.interfaces.launchpad import ILaunchpadCelebrities
 from lp.translations.interfaces.translationimportqueue import (
     ITranslationImportQueue, RosettaImportStatus)
 from canonical.launchpad.mail import simple_sendmail
 from canonical.launchpad.mailnotification import MailWrapper
-
-
-class ImportProcess:
+from canonical.launchpad.webapp import errorlog
+from lp.services.scripts.base import LaunchpadCronScript
+
+
+class TranslationsImport(LaunchpadCronScript):
     """Import .po and .pot files attached to Rosetta."""
-
-    def __init__(self, ztm, logger, max_seconds=3600):
-        """Initialize the ImportProcess object.
-
-        Arguments:
-
-        :param ztm: transaction manager to commit our individual imports.
-
-        :param logger: logging object to log informational messages and errors
-        to.
-
-        :param max_seconds: "alarm clock": after this many seconds, the job
-        should finish up even if there is more work for it to do.  This is a
-        mere guideline; actual processing time may be longer.
-        """
-        self.ztm = ztm
-        self.logger = logger
-        self.deadline = time.time() + max_seconds
-
-    def run(self):
-        """Execute the import of entries from the queue."""
-        # Get the queue.
+    # Time goal for one run.  It is not exact.  The script can run for
+    # longer than this, but will know to stop taking on new work.
+    # Since the script is run every 9 or 10 minutes, we set the goal
+    # at 8 minutes.  That leaves a bit of time to complete the last
+    # ongoing batch of imports.
+    time_to_run = timedelta(minutes=8)
+
+    # Failures to be reported in bulk at closing, so we don't accumulate
+    # thousands of oopses for repetitive errors.
+    failures = None
+
+    def __init__(self, *args, **kwargs):
+        super(TranslationsImport, self).__init__(*args, **kwargs)
+        self.failures = {}
+
+    def _describeEntry(self, entry):
+        """Identify `entry` in a human-readable way."""
+        if entry.import_into:
+            return "%s (id %d)" % (entry.import_into.title, entry.id)
+
+        if entry.sourcepackagename:
+            return "'%s' (id %d) in %s %s package %s" % (
+                entry.path, entry.id,
+                entry.distroseries.distribution.name,
+                entry.distroseries.displayname,
+                entry.sourcepackagename.name)
+        else:
+            return "'%s' (id %d) in %s" % (
+                entry.path, entry.id, entry.productseries.title)
+
+    def _reportOops(self, reason, entries, exc_info=None):
+        """Register an oops."""
+        if exc_info is None:
+            exc_info = sys.exc_info()
+        description = [
+            ('Reason', reason),
+            ('Queue entries', entries),
+            ]
+        errorlog.globalErrorUtility.raising(
+            exc_info, errorlog.ScriptRequest(description))
+
+    def _registerFailure(self, entry, reason, traceback=False, abort=False):
+        """Note that a queue entry is unusable in some way."""
+        entry.setStatus(RosettaImportStatus.FAILED)
+        entry.setErrorOutput(reason)
+
+        if abort:
+            traceback = True
+
+        description = self._describeEntry(entry)
+        message = "%s -- %s" % (reason, description)
+        self.logger.error(message, exc_info=traceback)
+
+        if abort:
+            # Serious enough to stop the script.  Register as an
+            # individual oops.
+            self._reportOops(self, reason, [description])
+        else:
+            # Register problem for bulk reporting later.
+            if not self.failures.get(reason):
+                self.failures[reason] = []
+            self.failures[reason].append(description)
+
+    def _checkEntry(self, entry):
+        """Sanity-check `entry` before importing."""
+        if entry.import_into is None:
+            self._registerFailure(
+                entry, "Entry is approved but has no place to import to.")
+            return False
+
+        template = entry.potemplate
+        if template:
+            if template.distroseries != entry.distroseries:
+                self._registerFailure(
+                    entry, "Entry was approved for the wrong distroseries.")
+                return False
+            if template.productseries != entry.productseries:
+                self._registerFailure(
+                    entry, "Entry was approved for the wrong productseries.")
+                return False
+
+        return True
+
+    def _importEntry(self, entry):
+        """Perform the import of one entry, and notify the uploader."""
+        self.logger.info('Importing: %s' % entry.import_into.title)
+        target = entry.import_into
+        (mail_subject, mail_body) = target.importFromQueue(entry, self.logger)
+
+        if mail_subject is not None:
+            # A `mail_subject` of None indicates that there
+            # is no notification worth sending out.
+            from_email = config.rosetta.admin_email
+            katie = getUtility(ILaunchpadCelebrities).katie
+            if entry.importer == katie:
+                # Email import state to Debian imports email.
+                to_email = config.rosetta.debian_import_email
+            else:
+                to_email = helpers.get_contact_email_addresses(entry.importer)
+
+            if to_email:
+                text = MailWrapper().format(mail_body)
+                simple_sendmail(from_email, to_email, mail_subject, text)
+
+    def main(self):
+        """Import entries from the queue."""
+        self.logger.debug("Starting the import process.")
+
+        errorlog.globalErrorUtility.configure('poimport')
+        self.deadline = datetime.now(UTC) + self.time_to_run
         translation_import_queue = getUtility(ITranslationImportQueue)
 
         # Get the list of each product or distroseries with pending imports.
@@ -60,138 +151,48 @@
             self.logger.info("No requests pending.")
             return
 
-        # XXX: JeroenVermeulen 2007-06-20: How on Earth do we test that the
-        # deadline code works?  It's only a small thing, and of course we'll
-        # notice that it works when we stop getting errors about this script
-        # not finishing.  Meanwhile, SteveA has suggested a more general
-        # solution.
-        while importqueues and time.time() < self.deadline:
-            # For fairness, service all queues at least once; don't check for
-            # deadline.  If we stopped halfway through the list of queues, we
-            # would accidentally favour queues that happened to come out at
-            # the front of the list.
+        have_work = True
+
+        while have_work and datetime.now(UTC) < self.deadline:
+            have_work = False
+
+            # For fairness, service all queues at least once; don't
+            # check for deadlines here or we'd favour some
+            # products/packages over others.
             for queue in importqueues:
-                # Make sure our previous state changes hit the database.
-                # Otherwise, getFirstEntryToImport() might pick up an entry
-                # we've already processed but haven't flushed yet.
-                # XXX: JeroenVermeulen 2007-11-29 bug=3989: should become
-                # unnecessary once Zopeless commit() improves.
-                flush_database_updates()
-
-                entry_to_import = queue.getFirstEntryToImport()
-                if entry_to_import is None:
-                    continue
-
-                if entry_to_import.import_into is None:
-                    if entry_to_import.sourcepackagename is not None:
-                        package = entry_to_import.sourcepackagename.name
-                    elif entry_to_import.productseries is not None:
-                        package = (
-                            entry_to_import.productseries.product.displayname)
-                    else:
-                        raise AssertionError(
-                            "Import queue entry %d has neither a "
-                            "source package name nor a product series."
-                            % entry_to_import.id)
-                    raise AssertionError(
-                        "Broken translation import queue entry %d (for %s): "
-                        "it's Approved but lacks the place where it should "
-                        "be imported!  A DBA will need to fix this by hand."
-                        % (entry_to_import.id, package))
-
-                # Do the import.
-                title = '[Unknown Title]'
-                try:
-                    title = entry_to_import.import_into.title
-                    self.logger.info('Importing: %s' % title)
-
-                    (mail_subject, mail_body) = (
-                        entry_to_import.import_into.importFromQueue(
-                            entry_to_import, self.logger))
-
-                    if mail_subject is not None:
-                        # A `mail_subject` of None indicates that there
-                        # is no notification worth sending out.
-                        from_email = config.rosetta.admin_email
-                        katie = getUtility(ILaunchpadCelebrities).katie
-                        if entry_to_import.importer == katie:
-                            # Email import state to Debian imports email.
-                            to_email = config.rosetta.debian_import_email
-                        else:
-                            to_email = helpers.get_contact_email_addresses(
-                                entry_to_import.importer)
-
-                        if to_email:
-                            text = MailWrapper().format(mail_body)
-
-                            # XXX: JeroenVermeulen 2007-11-29 bug=29744: email
-                            # isn't transactional in zopeless mode.  That
-                            # means that our current transaction can fail
-                            # after we already sent out a success
-                            # notification.  To prevent that, we commit the
-                            # import (attempt) before sending out the email.
-                            # That way the worst that can happen is that an
-                            # email goes missing.
-                            # Once bug 29744 is fixed, this commit must die so
-                            # the email and the import will be in a single
-                            # atomic operation.
-                            self.ztm.commit()
-                            self.ztm.begin()
-
-                            simple_sendmail(
-                                from_email, to_email, mail_subject, text)
-
-                except KeyboardInterrupt:
-                    self.ztm.abort()
-                    raise
-                except AssertionError:
-                    raise
-                except:
-                    # If we have any exception, log it, abort the transaction
-                    # and set the status to FAILED.
-                    self.logger.error('Got an unexpected exception while'
-                                      ' importing %s' % title, exc_info=1)
-                    # We are going to abort the transaction, need to save the
-                    # id of this entry to update its status.
-                    failed_entry_id = entry_to_import.id
-                    self.ztm.abort()
-                    # Get the needed objects to set the failed entry status as
-                    # FAILED.
-                    self.ztm.begin()
-                    translation_import_queue = getUtility(
-                        ITranslationImportQueue)
-                    entry_to_import = translation_import_queue[
-                        failed_entry_id]
-                    entry_to_import.setStatus(RosettaImportStatus.FAILED)
-                    self.ztm.commit()
-                    self.ztm.begin()
-                    # Go to process next entry.
-                    continue
-
-                # As soon as the import is done, we commit the transaction
-                # so it's not lost.
-                try:
-                    self.ztm.commit()
-                    self.ztm.begin()
-                except KeyboardInterrupt:
-                    self.ztm.abort()
-                    raise
-                except:
-                    # If we have any exception, we log it and abort the
-                    # transaction.
-                    self.logger.error(
-                        'We got an unexpected exception while committing the '
-                        'transaction',
-                        exc_info=1)
-                    self.ztm.abort()
-                    self.ztm.begin()
-
-            # Refresh the list of objects with pending imports.
-            importqueues = (
-                translation_import_queue.getRequestTargets(
-                    RosettaImportStatus.APPROVED))
-
-        if not importqueues:
+                entry = queue.getFirstEntryToImport()
+                if entry is None:
+                    continue
+
+                have_work = True
+
+                try:
+                    if self._checkEntry(entry):
+                        self._importEntry(entry)
+                    if self.txn:
+                        self.txn.commit()
+                except KeyboardInterrupt:
+                    raise
+                except (AssertionError, SystemError), e:
+                    self._registerFailure(entry, e, abort=True)
+                    raise
+                except Exception, e:
+                    if self.txn:
+                        self.txn.abort()
+                    self._registerFailure(entry, e, traceback=True)
+                    if self.txn:
+                        self.txn.commit()
+
+        if have_work:
+            self.logger.info("Used up available time.")
+        else:
             self.logger.info("Import requests completed.")
-        else:
-            self.logger.info("Used up available time.")
+
+        self._reportFailures()
+
+        self.logger.debug("Finished the import process.")
+
+    def _reportFailures(self):
+        """Bulk-report deferred failures as oopses."""
+        for reason, entries in self.failures.iteritems():
+            self._reportOops(reason, entries)

=== added file 'lib/lp/translations/scripts/tests/test_translations_import.py'
--- lib/lp/translations/scripts/tests/test_translations_import.py	1970-01-01 00:00:00 +0000
+++ lib/lp/translations/scripts/tests/test_translations_import.py	2009-10-01 11:13:16 +0000
@@ -0,0 +1,110 @@
+# Copyright 2009 Canonical Ltd.  This software is licensed under the
+# GNU Affero General Public License version 3 (see the file LICENSE).
+
+import logging
+import re
+
+from unittest import TestLoader
+
+from lp.testing import TestCaseWithFactory
+from canonical.testing.layers import LaunchpadScriptLayer
+
+from lp.translations.model.translationimportqueue import (
+    TranslationImportQueue)
+from lp.translations.scripts.po_import import TranslationsImport
+
+
+class TestTranslationsImport(TestCaseWithFactory):
+
+    layer = LaunchpadScriptLayer
+
+    def setUp(self):
+        super(TestTranslationsImport, self).setUp()
+        self.queue = TranslationImportQueue()
+        self.script = TranslationsImport('poimport', test_args=[])
+        self.script.logger.setLevel(logging.FATAL)
+        self.owner = self.factory.makePerson()
+
+    def _makeProductSeries(self):
+        """Make a product series called 'trunk'."""
+        return self.factory.makeProduct(owner=self.owner).getSeries('trunk')
+
+    def _makeEntry(self, path, **kwargs):
+        """Produce a queue entry."""
+        return self.queue.addOrUpdateEntry(
+            path, '# Nothing here', False, self.owner, **kwargs)
+
+    def test_describeEntry_without_target(self):
+        productseries = self._makeProductSeries()
+        entry = self._makeEntry('foo.po', productseries=productseries)
+        description = self.script._describeEntry(entry)
+        pattern = "'foo.po' \(id [0-9]+\) in [A-Za-z0-9_-]+ trunk series$"
+        self.assertNotEqual(None, re.match(pattern, description))
+
+    def test_describeEntry_for_pofile(self):
+        productseries = self._makeProductSeries()
+        template = self.factory.makePOTemplate(productseries=productseries)
+        pofile = template.newPOFile('nl')
+        entry = self._makeEntry(
+            'foo.po', productseries=productseries, potemplate=template,
+            pofile=pofile)
+        description = self.script._describeEntry(entry)
+        pattern = "Dutch \(nl\) translation of .* in .* trunk \(id [0-9]+\)$"
+        self.assertNotEqual(None, re.match(pattern, description))
+
+    def test_describeEntry_for_template(self):
+        productseries = self._makeProductSeries()
+        template = self.factory.makePOTemplate(productseries=productseries)
+        entry = self._makeEntry(
+            'foo.pot', productseries=productseries, potemplate=template)
+        description = self.script._describeEntry(entry)
+        pattern = 'Template "[^"]+" in [A-Za-z0-9_-]+ trunk \(id [0-9]+\)$'
+        self.assertNotEqual(None, re.match(pattern, description))
+
+    def test_checkEntry(self):
+        productseries = self._makeProductSeries()
+        template = self.factory.makePOTemplate(productseries=productseries)
+        entry = self._makeEntry(
+            'foo.pot', productseries=productseries, potemplate=template)
+        self.assertTrue(self.script._checkEntry(entry))
+
+    def test_checkEntry_without_target(self):
+        productseries = self._makeProductSeries()
+        entry = self._makeEntry('foo.pot', productseries=productseries)
+        self.assertFalse(self.script._checkEntry(entry))
+        self.assertIn(
+            "Entry is approved but has no place to import to.",
+            self.script.failures.keys())
+
+    def test_checkEntry_misapproved_product(self):
+        productseries = self._makeProductSeries()
+        template = self.factory.makePOTemplate()
+        entry = self._makeEntry(
+            'foo.pot', productseries=productseries, potemplate=template)
+        self.assertNotEqual(None, entry.import_into)
+
+        self.assertFalse(self.script._checkEntry(entry))
+        self.assertIn(
+            "Entry was approved for the wrong productseries.",
+            self.script.failures.keys())
+
+    def test_checkEntry_misapproved_package(self):
+        package = self.factory.makeSourcePackage()
+        other_series = self.factory.makeDistroRelease(
+            distribution=package.distroseries.distribution)
+        template = self.factory.makePOTemplate(
+            distroseries=package.distroseries,
+            sourcepackagename=package.sourcepackagename)
+        entry = self._makeEntry(
+            'foo.pot', sourcepackagename=package.sourcepackagename,
+            distroseries=other_series, potemplate=template)
+        self.assertNotEqual(None, entry.import_into)
+
+        self.assertFalse(self.script._checkEntry(entry))
+        self.assertIn(
+            "Entry was approved for the wrong distroseries.",
+            self.script.failures.keys())
+
+
+def test_suite():
+    return TestLoader().loadTestsFromName(__name__)