Merge lp:~jtv/launchpad/bug-407590 into lp:launchpad

[Jeroen T. Vermeulen]

[Jeroen T. Vermeulen (jtv)]

= Bug 407590 =

384 lines of diff.

We have a cron script that exports snapshots of a ProductSeries'
translations to a bzr branch. Bug 407590 is that currently, this script
exports every POFile again at every run. This branch fixes that.

It's not as easy as it seems to find out whether a POFile has changed
since its last export. There is an attribute POFile.date_changed, but
that marks the beginning of the last change operation rather than its
completion. Worse, the timestamp on the last commit to the branch marks
the completion of the last export. For a conservative estimate of
whether a POFile had changed since the last export, we'd need these
exactly the other way around.

A more accurate solution would be to go through the files stored in the
branch and read the export dates from their headers. But that would
involve accessing the actual branch data and so risk the performance and
scalability that the script currently has.

We could also have extended our database schema to store timing
information, but that adds complexity at a time when we are more focused
on the 3.0 release. It's also easy to make subtle mistakes in how the
information is associated with branches or productseries and when it
should be cleared.

Instead, I chose to get the date of the last translations commit to the
branch and subtract a fixed "fudge factor." As long as the error in the
time window is less than this fudge factor, the worst that can happen is
that a file is exported more often than needed. That's basically what
is already happening anyway, just less of it. Dirty, simple, and
probably effective.

== Performance ==

The performance overhead of this approach is limited to fetching past
revisions to the branch. Typically several revisions will fit in a
single disk block, so fetching these should be quite cheap. To avoid
scanning very long histories in vain, there is a cutoff age: if the
script fails to find a previous translations commit in the past week, it
assumes that there isn't one and just exports everything.

We may want to improve on this algorithm in the feature. For now, it
should cut down on the script's workload enough to avoid its performance
problems with ddtp-ubuntu, which currently takes over 6 hours to export
in full.

Actually, there was another problem with the ddtp-ubuntu exports: their
memory usage. Just in case we're keeping semantic garbage referenced,
I also added some clearing of POTemplate's internal POFile cache. I
have no particular indication that this will solve the problem, but it's
a cheap win if it does.

== Diff details ==

In translations_to_branch.py, _makeDirectBranchCommit: the parameter was
called bzrbranch, but that was simply wrong. It was always a Launchpad
Branch object.

_isTranslationsCommit recognizes the translations commits by their fixed
commit message. We considered tagging the commits, but that turned out
to be harder than expected and require extending the bzrlib API. There
is also the username, but that might change as easily as the commit
message. Plus, in the future we may sometimes find it useful for users
to be able to fake a translations commit e.g. to prevent very large
sudden e...

[Brad Crittenden (bac)]

Jeroen this fix looks good. I think you've made a reasoned choice for your approach and the implementation and testing looks a-ok.

Could I trouble you to change the output message at line 25 to be "Committed %d" and the corresponding tests? It just reads better and is consistent.

Thanks for the fix.

review: Approve

=== modified file 'lib/lp/translations/doc/translations-export-to-branch.txt'
--- lib/lp/translations/doc/translations-export-to-branch.txt	2009-08-03 11:40:57 +0000
+++ lib/lp/translations/doc/translations-export-to-branch.txt	2009-09-15 15:30:59 +0000
@@ -26,8 +26,9 @@
 
     >>> class MockDirectBranchCommit:
     ...     """Mock DirectBranchCommit.  Prints actions."""
-    ...
     ...     simulate_race = False
+    ...     bzrbranch = None
+    ...     written_files = 0
     ...
     ...     def __init__(self, logger):
     ...         self.logger = logger
@@ -35,6 +36,7 @@
     ...     def writeFile(self, path, contents):
     ...         self.logger.info("Writing file '%s':" % path)
     ...         self.logger.info(contents)
+    ...         self.written_files += 1
     ...
     ...     def lockForCommit(self):
     ...         pass
@@ -45,7 +47,7 @@
     ...
     ...     def commit(self, message=None):
     ...         self._checkForRace()
-    ...         self.logger.info("Commit.")
+    ...         self.logger.info("Commit %d file(s)." % self.written_files)
     ...
     ...     def unlock(self):
     ...         self.logger.info("Unlock.")
@@ -53,14 +55,18 @@
     >>> from canonical.launchpad.scripts.logger import FakeLogger
 
     >>> class MockExportTranslationsToBranch(ExportTranslationsToBranch):
-    ...
+    ...     """Test version of ExportTranslationsToBranch."""
     ...     simulate_race = False
+    ...     simulated_latest_commit = None
     ...
     ...     def __init__(self, *args, **kwargs):
     ...         super(MockExportTranslationsToBranch, self).__init__(
     ...             *args, **kwargs)
     ...         self.logger = FakeLogger()
     ...
+    ...     def _getLatestTranslationsCommit(self, branch):
+    ...         return self.simulated_latest_commit
+    ...
     ...     def _makeDirectBranchCommit(self, bzrbranch):
     ...         committer = MockDirectBranchCommit(self.logger)
     ...         committer.simulate_race = self.simulate_race
@@ -106,14 +112,16 @@
     ...
     ...     if not iscurrent:
     ...         removeSecurityProxy(template).iscurrent = False
+    ...
+    ...     return pofile
 
-    >>> main_template = setup_template_and_translations(
+    >>> main_pofile = setup_template_and_translations(
     ...     'po/main/gazpot.pot', 'maingazpot')
 
-    >>> module_template = setup_template_and_translations(
+    >>> module_pofile = setup_template_and_translations(
     ...     'po/module/module.pot', 'gazmod')
 
-    >>> old_template = setup_template_and_translations(
+    >>> old_pofile = setup_template_and_translations(
     ...     'po/gazpot.pot', 'oldgazpot', iscurrent=False)
 
 When the translations-export-to-branch script runs, it feeds the
@@ -125,6 +133,7 @@
     >>> script.main()
     INFO Exporting to translations branches.
     INFO Exporting Gazblachko trunk series.
+    DEBUG No previous translations commit found.
     INFO Writing file 'po/main/nl.po':
     INFO # ...
     msgid ""
@@ -143,7 +152,7 @@
     <BLANKLINE>
     msgid "gazmod msgid"
     msgstr "gazmod msgstr"
-    INFO Commit.
+    INFO Commit 2 file(s).
     INFO Unlock.
     INFO Processed 1 item(s); 0 failure(s).
 
@@ -156,8 +165,49 @@
     INFO Exporting to translations branches.
     INFO Processed 0 item(s); 0 failure(s).
 
-
-== Race conditions ==
+    >>> gazblachko.official_rosetta = True
+    >>> transaction.commit()
+
+
+Incremental exports
+-------------------
+
+If the script detects that POFiles have not been touched roughly since
+the time it last exported them, it won't export them again.
+
+    >>> from datetime import datetime, timedelta
+    >>> from pytz import UTC
+    >>> now = datetime.now(UTC)
+    >>> script.simulated_latest_commit = now
+    >>> main_pofile.date_changed = now - timedelta(days=3)
+    >>> module_pofile.date_changed = now - timedelta(days=4)
+    >>> old_pofile.date_changed = now - timedelta(days=5)
+
+    >>> script.main()
+    INFO Exporting to translations branches.
+    INFO Exporting Gazblachko trunk series.
+    DEBUG Last commit was at ....
+    INFO Commit 0 file(s).
+    INFO Unlock.
+    INFO Processed 1 item(s); 0 failure(s).
+
+If one of the files is updated, it is exported again.  Unchanged files
+are not.
+
+    >>> main_pofile.date_changed = now
+    >>> script.main()
+    INFO Exporting to translations branches.
+    INFO Exporting Gazblachko trunk series.
+    DEBUG Last commit was at ...
+    INFO Writing file 'po/main/nl.po':
+    INFO ...
+    INFO Commit 1 file(s).
+    INFO Unlock.
+    INFO Processed 1 item(s); 0 failure(s).
+
+
+Race conditions
+---------------
 
 The script checks for possible race conditions.  Otherwise it might
 overwrite translations committed to the branch that hadn't been
@@ -174,13 +224,12 @@
 If the DirectBranchCommit detects a concurrent update, the script will
 refuse to commit to the branch.
 
-    >>> gazblachko.official_rosetta = True
-    >>> transaction.commit()
-
     >>> script.simulate_race = True
+    >>> script.simulated_latest_commit = None
     >>> script.main()
     INFO Exporting to translations branches.
     INFO Exporting Gazblachko trunk series.
+    DEBUG No previous translations commit found.
     INFO Writing file 'po/main/nl.po':
     ...
     msgstr "gazmod msgstr"

=== modified file 'lib/lp/translations/interfaces/potemplate.py'
--- lib/lp/translations/interfaces/potemplate.py	2009-07-29 18:53:50 +0000
+++ lib/lp/translations/interfaces/potemplate.py	2009-09-15 15:30:59 +0000
@@ -319,6 +319,16 @@
     def __iter__():
         """Return an iterator over current `IPOTMsgSet` in this template."""
 
+    def clearPOFileCache():
+        """Clear `POFile`-related cached data.
+
+        As you work with a `POTemplate`, some data about its `POFile`s
+        gets cached.  But if you're iterating over the template's
+        translations one `POFile` at a time, you can drop any cached
+        data about a `POFile` as soon as you're done with it.  Use this
+        method to do that.
+        """
+
     def getHeader():
         """Return an `ITranslationHeaderData` representing its header."""
 

=== modified file 'lib/lp/translations/model/potemplate.py'
--- lib/lp/translations/model/potemplate.py	2009-08-05 14:54:11 +0000
+++ lib/lp/translations/model/potemplate.py	2009-09-15 15:30:59 +0000
@@ -182,8 +182,12 @@
     _uses_english_msgids = None
 
     def __storm_invalidated__(self):
+        self.clearPOFileCache()
+        self._uses_english_msgids = None
+
+    def clearPOFileCache(self):
+        """See `IPOTemplate`."""
         self._cached_pofiles_by_language = None
-        self._uses_english_msgids = None
 
     @property
     def uses_english_msgids(self):

=== modified file 'lib/lp/translations/scripts/tests/test_translations_to_branch.py'
--- lib/lp/translations/scripts/tests/test_translations_to_branch.py	2009-07-17 18:47:44 +0000
+++ lib/lp/translations/scripts/tests/test_translations_to_branch.py	2009-09-15 15:30:59 +0000
@@ -9,8 +9,6 @@
 
 from textwrap import dedent
 
-from bzrlib.branch import Branch
-
 from zope.security.proxy import removeSecurityProxy
 
 from canonical.launchpad.scripts.tests import run_script
@@ -23,6 +21,12 @@
 
     layer = ZopelessAppServerLayer
 
+    def _filterOutput(self, output):
+        """Remove DEBUG lines from output."""
+        return '\n'.join([
+            line for line in output.splitlines()
+            if not line.startswith('DEBUG')])
+
     def test_translations_export_to_branch(self):
         # End-to-end test of the script doing its work.
 
@@ -60,15 +64,16 @@
 
         # Run The Script.
         retcode, stdout, stderr = run_script(
-            'cronscripts/translations-export-to-branch.py', [])
+            'cronscripts/translations-export-to-branch.py', ['-vvv'])
 
         self.assertEqual('', stdout)
         self.assertEqual(
             'INFO    creating lockfile\n'
             'INFO    Exporting to translations branches.\n'
             'INFO    Exporting Committobranch trunk series.\n'
-            'INFO    Processed 1 item(s); 0 failure(s).\n',
-            stderr)
+            'INFO    Processed 1 item(s); 0 failure(s).',
+            self._filterOutput(stderr))
+        self.assertIn('No previous translations commit found.', stderr)
         self.assertEqual(0, retcode)
 
         # The branch now contains a snapshot of the translation.  (Only
@@ -102,6 +107,13 @@
             if not re.match(pattern, contents, re.MULTILINE):
                 self.assertEqual(pattern, contents)
 
+        # If we run the script again at this point, it won't export
+        # anything because it sees that the POFile has not been changed
+        # since the last export.
+        retcode, stdout, stderr = run_script(
+            'cronscripts/translations-export-to-branch.py', ['-vvv'])
+        self.assertIn('Last commit was at', stderr)
+
 
 def test_suite():
     return unittest.TestLoader().loadTestsFromName(__name__)

=== modified file 'lib/lp/translations/scripts/translations_to_branch.py'
--- lib/lp/translations/scripts/translations_to_branch.py	2009-08-03 11:34:35 +0000
+++ lib/lp/translations/scripts/translations_to_branch.py	2009-09-15 15:30:59 +0000
@@ -8,6 +8,9 @@
 
 
 import os.path
+from datetime import datetime, timedelta
+from pytz import UTC
+
 from zope.component import getUtility
 
 from storm.expr import Join, SQL
@@ -27,6 +30,19 @@
 class ExportTranslationsToBranch(LaunchpadCronScript):
     """Commit translations to translations_branches where requested."""
 
+    commit_message = "Launchpad automatic translations update."
+
+    # Don't bother looking for a previous translations commit if it's
+    # longer than this ago.
+    previous_commit_cutoff_age = timedelta(days=7)
+
+    # We can find out when the last translations commit to a branch
+    # completed, and we can find out when the last transaction changing
+    # a POFile started.  This is exactly the wrong way around for
+    # figuring out which POFiles need a fresh export, so assume a fudge
+    # factor.
+    fudge_factor = timedelta(hours=6)
+
     def _checkForObjections(self, source):
         """Check for reasons why we can't commit to this branch.
 
@@ -46,17 +62,42 @@
                 "Translations branch for %s has pending translations "
                 "changes.  Not committing." % source.title)
 
-    def _makeDirectBranchCommit(self, bzrbranch):
+    def _makeDirectBranchCommit(self, db_branch):
         """Create a `DirectBranchCommit`.
 
         This factory is a mock-injection point for tests.
+
+        :param db_branch: A `Branch` object as defined in Launchpad.
+        :return: A `DirectBranchCommit` for `db_branch`.
         """
-        return DirectBranchCommit(bzrbranch)
+        return DirectBranchCommit(db_branch)
 
     def _commit(self, source, committer):
         """Commit changes to branch.  Check for race conditions."""
         self._checkForObjections(source)
-        committer.commit("Launchpad automatic translations update.")
+        committer.commit(self.commit_message)
+
+    def _isTranslationsCommit(self, revision):
+        """Is `revision` an automatic translations commit?"""
+        return revision.message == self.commit_message
+
+    def _getLatestTranslationsCommit(self, branch):
+        """Get date of last translations commit to `branch`, if any."""
+        cutoff_date = datetime.now(UTC) - self.previous_commit_cutoff_age
+
+        revno, current_rev = branch.last_revision_info()
+        repository = branch.repository
+        for rev_id in repository.iter_reverse_revision_history(current_rev):
+            revision = repository.get_revision(rev_id)
+            revision_date = revision.timestamp
+            if self._isTranslationsCommit(revision):
+                return revision_date
+
+            if revision_date < cutoff_date:
+                # Going too far back in history.  Give up.
+                return None
+
+        return None
 
     def _exportToBranch(self, source):
         """Export translations for source into source.translations_branch.
@@ -68,6 +109,22 @@
 
         committer = self._makeDirectBranchCommit(source.translations_branch)
 
+        bzr_branch = committer.bzrbranch
+
+        last_commit_date = self._getLatestTranslationsCommit(bzr_branch)
+
+        if last_commit_date is None:
+            self.logger.debug("No previous translations commit found.")
+            changed_since = None
+        else:
+            # Export files that have been touched since the last export.
+            # Subtract a fudge factor because the last-export date marks
+            # the end of the previous export, and the POFiles'
+            # last-touched timestamp marks the beginning of the last
+            # transaction that changed them.
+            self.logger.debug("Last commit was at %s." % last_commit_date)
+            changed_since = last_commit_date - self.fudge_factor
+
         try:
             subset = getUtility(IPOTemplateSet).getSubset(
                 productseries=source, iscurrent=True)
@@ -75,6 +132,13 @@
                 base_path = os.path.dirname(template.path)
 
                 for pofile in template.pofiles:
+
+                    has_changed = (
+                        changed_since is None or
+                        pofile.date_changed > changed_since)
+                    if not has_changed:
+                        continue
+
                     pofile_path = os.path.join(
                         base_path, pofile.getFullLanguageCode() + '.po')
                     pofile_contents = pofile.export()
@@ -87,6 +151,10 @@
                     if self.txn:
                         self.txn.commit()
 
+                    # We're done with this POFile.  Don't bother caching
+                    # anything about it any longer.
+                    template.clearPOFileCache()
+
             self._commit(source, committer)
         finally:
             committer.unlock()