Merge lp:~jtv/launchpad/db-bug-435655 into lp:launchpad/db-devel

[Jeroen T. Vermeulen]

[Jeroen T. Vermeulen (jtv)]

= Bug 435655 =

This branch fixes critical breakage in the translations-to-branch export
script.

In 3.0 we gave this script the ability to skip exports for POFiles in a
branch that hadn't changed since their previous export run. This change
broke because the timestamp on the bzr revision that we got this
information from is not a datetime. It's a float representing seconds
since the epoch, UTC-based.

As it turns out there was a test that exercised this code, and it did
trigger the exception, but since it happened in a script run and was
handled there, the exception did not propagate into the test. Explicit
checks of the script run's results were needed.

I had to do some reverse engineering to figure out the details. As it
turns out, even the bzr experts did not know exactly how to interpret
and convert the timestamp.

You may notice that I also made the script avoid its commit when there
are no changes. This is mostly duplicative of a similar check further
down the call tree, in DirectBranchCommit. But it also circumvents the
check for commit conflicts, which simplifies the tests. Otherwise, I'd
either have to patch up the last_scanned_id for the branch object, or
let the test spit out a "branch has changed" error when it's really not
supposed to change anything in the branch anyway.

Test:
{{{
./bin/test -vv -t translations.*to.branch
}}}

Q/A is difficult, since this script must run on the codehosting server
where the branches are hosted. This pretty much rules out staging.

[Michael Nelson (michael.nelson)]

Great stuff jtv.
r=me - two questions below.

Thanks!

> = Bug 435655 =
>
> This branch fixes critical breakage in the translations-to-branch export
> script.
>
> In 3.0 we gave this script the ability to skip exports for POFiles in a
> branch that hadn't changed since their previous export run. This change
> broke because the timestamp on the bzr revision that we got this
> information from is not a datetime. It's a float representing seconds
> since the epoch, UTC-based.
>
> As it turns out there was a test that exercised this code, and it did
> trigger the exception, but since it happened in a script run and was
> handled there, the exception did not propagate into the test. Explicit
> checks of the script run's results were needed.

Great! OK, the setup in your test has convinced me that translations is
the new soyuz ;). I've just annotated your changes to ensure I've
understood the situation correctly.

>
> I had to do some reverse engineering to figure out the details. As it
> turns out, even the bzr experts did not know exactly how to interpret
> and convert the timestamp.
>
> You may notice that I also made the script avoid its commit when there
> are no changes. This is mostly duplicative of a similar check further
> down the call tree, in DirectBranchCommit. But it also circumvents the
> check for commit conflicts, which simplifies the tests. Otherwise, I'd
> either have to patch up the last_scanned_id for the branch object, or
> let the test spit out a "branch has changed" error when it's really not
> supposed to change anything in the branch anyway.
>
> Test:
> {{{
> ./bin/test -vv -t translations.*to.branch
> }}}
>
> Q/A is difficult, since this script must run on the codehosting server
> where the branches are hosted. This pretty much rules out staging.

> === modified file 'lib/lp/translations/doc/translations-export-to-branch.txt'
> --- lib/lp/translations/doc/translations-export-to-branch.txt 2009-09-16 06:57:35 +0000
> +++ lib/lp/translations/doc/translations-export-to-branch.txt 2009-09-24 08:57:28 +0000
> @@ -187,7 +187,6 @@
> INFO Exporting to translations branches.
> INFO Exporting Gazblachko trunk series.
> DEBUG Last commit was at ....
> - INFO Committed 0 file(s).
> INFO Unlock.
> INFO Processed 1 item(s); 0 failure(s).
>

OK, so this is due to skipping the commit when there are no changes.

>
> === modified file 'lib/lp/translations/scripts/tests/test_translations_to_branch.py'
> --- lib/lp/translations/scripts/tests/test_translations_to_branch.py 2009-09-15 15:30:59 +0000
> +++ lib/lp/translations/scripts/tests/test_translations_to_branch.py 2009-09-24 08:57:28 +0000
> @@ -111,8 +111,11 @@
> # 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'])
> + 'cronscripts/translations-export-to-branch.py',
> + ['-vvv', '--no-fudge'])
> + self.assertEqual(0, retcode)
> self.assertIn('Last commit was at', stderr)
> + self.assertIn("Processed 1 item(s); 0 failure(s)....

review: Approve (code)

[Jeroen T. Vermeulen (jtv)]

> Great stuff jtv.
> r=me - two questions below.

Thanks for the fast review! Read on...

> > === modified file 'lib/lp/translations/doc/translations-export-to-
> branch.txt'
> > --- lib/lp/translations/doc/translations-export-to-branch.txt 2009-09-16
> 06:57:35 +0000
> > +++ lib/lp/translations/doc/translations-export-to-branch.txt 2009-09-24
> 08:57:28 +0000
> > @@ -187,7 +187,6 @@
> > INFO Exporting to translations branches.
> > INFO Exporting Gazblachko trunk series.
> > DEBUG Last commit was at ....
> > - INFO Committed 0 file(s).
> > INFO Unlock.
> > INFO Processed 1 item(s); 0 failure(s).
> >
>
> OK, so this is due to skipping the commit when there are no changes.

Yes.

> > === modified file
> 'lib/lp/translations/scripts/tests/test_translations_to_branch.py'
> > --- lib/lp/translations/scripts/tests/test_translations_to_branch.py
> 2009-09-15 15:30:59 +0000
> > +++ lib/lp/translations/scripts/tests/test_translations_to_branch.py
> 2009-09-24 08:57:28 +0000
> > @@ -111,8 +111,11 @@
> > # 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'])
> > + 'cronscripts/translations-export-to-branch.py',
> > + ['-vvv', '--no-fudge'])
> > + self.assertEqual(0, retcode)
> > self.assertIn('Last commit was at', stderr)
> > + self.assertIn("Processed 1 item(s); 0 failure(s).", stderr)
> >
>
> Right - so now you're checking that it didn't error, and that it did
> process an item. Is it worth here explicitely asserting that
> 'INFO Committed' is not in stderr? (It's already part of the documentation
> above.)

Excellent idea! I'm going with it. Using regexes to search for it.

> > === modified file 'lib/lp/translations/scripts/translations_to_branch.py'
> > --- lib/lp/translations/scripts/translations_to_branch.py 2009-09-15
> 15:30:59 +0000
> > +++ lib/lp/translations/scripts/translations_to_branch.py 2009-09-24

> > @@ -81,6 +88,13 @@
> > """Is `revision` an automatic translations commit?"""
> > return revision.message == self.commit_message
> >
> > + def _getRevisionTime(self, revision):
> > + """Get timestamp of `revision`."""
> > + # The bzr timestamp is a float representing UTC-based seconds
> > + # since the epoch. It stores the timezone as well, but we can
> > + # ignore it here.
> > + return datetime.fromtimestamp(revision.timestamp, UTC)
> > +
>
> Is this a separate method because you thought you'd need to re-use it? or
> just to encapsulate the comment? Normally I'd not do that for a single
> line unless it was being re-used. It could simply go in the method below
> right?

It's mostly because getting it right turned out to be difficult. If even
lifeless doesn't know how to get a piece of information from bzrlib, when
you do finally figure it out, it's worth isolating!

I know, it doesn't look like much. But what we have in the revision is: a
"timestamp" of unclear type, and a "timezone" which isn't a timezone but an
...

[Brad Crittenden (bac)]

review: Approve (release-critical)

=== modified file 'lib/lp/translations/doc/translations-export-to-branch.txt'
--- lib/lp/translations/doc/translations-export-to-branch.txt	2009-09-16 06:57:35 +0000
+++ lib/lp/translations/doc/translations-export-to-branch.txt	2009-09-24 09:51:12 +0000
@@ -187,7 +187,6 @@
     INFO Exporting to translations branches.
     INFO Exporting Gazblachko trunk series.
     DEBUG Last commit was at ....
-    INFO Committed 0 file(s).
     INFO Unlock.
     INFO Processed 1 item(s); 0 failure(s).
 

=== modified file 'lib/lp/translations/scripts/tests/test_translations_to_branch.py'
--- lib/lp/translations/scripts/tests/test_translations_to_branch.py	2009-09-15 15:30:59 +0000
+++ lib/lp/translations/scripts/tests/test_translations_to_branch.py	2009-09-24 09:51:12 +0000
@@ -111,8 +111,13 @@
         # 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'])
+            'cronscripts/translations-export-to-branch.py',
+            ['-vvv', '--no-fudge'])
+        self.assertEqual(0, retcode)
         self.assertIn('Last commit was at', stderr)
+        self.assertIn("Processed 1 item(s); 0 failure(s).", stderr)
+        self.assertEqual(
+            None, re.search("INFO\s+Committed [0-9]+ file", stderr))
 
 
 def test_suite():

=== modified file 'lib/lp/translations/scripts/translations_to_branch.py'
--- lib/lp/translations/scripts/translations_to_branch.py	2009-09-15 15:30:59 +0000
+++ lib/lp/translations/scripts/translations_to_branch.py	2009-09-24 09:51:12 +0000
@@ -43,6 +43,13 @@
     # factor.
     fudge_factor = timedelta(hours=6)
 
+    def add_my_options(self):
+        """See `LaunchpadScript`."""
+        self.parser.add_option(
+            '-n', '--no-fudge', action='store_true', dest='no_fudge',
+            default=False,
+            help="For testing: no fudge period for POFile changes.")
+
     def _checkForObjections(self, source):
         """Check for reasons why we can't commit to this branch.
 
@@ -81,6 +88,13 @@
         """Is `revision` an automatic translations commit?"""
         return revision.message == self.commit_message
 
+    def _getRevisionTime(self, revision):
+        """Get timestamp of `revision`."""
+        # The bzr timestamp is a float representing UTC-based seconds
+        # since the epoch.  It stores the timezone as well, but we can
+        # ignore it here.
+        return datetime.fromtimestamp(revision.timestamp, UTC)
+
     def _getLatestTranslationsCommit(self, branch):
         """Get date of last translations commit to `branch`, if any."""
         cutoff_date = datetime.now(UTC) - self.previous_commit_cutoff_age
@@ -89,7 +103,7 @@
         repository = branch.repository
         for rev_id in repository.iter_reverse_revision_history(current_rev):
             revision = repository.get_revision(rev_id)
-            revision_date = revision.timestamp
+            revision_date = self._getRevisionTime(revision)
             if self._isTranslationsCommit(revision):
                 return revision_date
 
@@ -125,6 +139,8 @@
             self.logger.debug("Last commit was at %s." % last_commit_date)
             changed_since = last_commit_date - self.fudge_factor
 
+        change_count = 0
+
         try:
             subset = getUtility(IPOTemplateSet).getSubset(
                 productseries=source, iscurrent=True)
@@ -144,6 +160,7 @@
                     pofile_contents = pofile.export()
 
                     committer.writeFile(pofile_path, pofile_contents)
+                    change_count += 1
 
                     # We're not actually writing any changes to the
                     # database, but it's not polite to stay in one
@@ -155,7 +172,8 @@
                     # anything about it any longer.
                     template.clearPOFileCache()
 
-            self._commit(source, committer)
+            if change_count > 0:
+                self._commit(source, committer)
         finally:
             committer.unlock()
 
@@ -193,6 +211,9 @@
         from lp.registry.model.product import Product
         from lp.registry.model.productseries import ProductSeries
 
+        if self.options.no_fudge:
+            self.fudge_factor = timedelta(0)
+
         self.logger.info("Exporting to translations branches.")
 
         self.store = getUtility(IStoreSelector).get(MAIN_STORE, SLAVE_FLAVOR)