Merge lp:~thumper/launchpad/bugjam-619555-request-builds-logging into lp:launchpad

[Tim Penhey]

[r=benji,edwin-grubbs][ui=none][bug=619555] Log extra detail in the request_daily_builds cron script.

LOSAs have requested that we add extra debugging to record which recipes are having their daily builds requested. This is a pretty trivial change.

[Benji York (benji)]

Nice, straight-forward branch.

The only thing I can suggest is that the conditional in TestLogger.log() is unnecessary. If args is an empty tuple, then "msg %= args" will leave msg as it was.

review: Approve (code*)

[Edwin Grubbs (edwin-grubbs)]

> Nice, straight-forward branch.
>
> The only thing I can suggest is that the conditional in TestLogger.log() is
> unnecessary. If args is an empty tuple, then "msg %= args" will leave msg as
> it was.

The MockLogger has a comment saying that they check whether args is empty, so that msg will not blow up if it contains formatting strings. It looks like logging.LogRecord.getMessage() has the same type of logic, so it would be worthwhile to keep.

I think that TestLogger should either subclass from FakeLogger, or TestLogger should be removed, and BufferLogger should be used in its place. We're beginning to get as many logger classes as Linux has text editors.

review: Approve (code)

[Tim Penhey (thumper)]

Updated to use the BufferLogger.

=== modified file 'cronscripts/request_daily_builds.py'
--- cronscripts/request_daily_builds.py	2010-06-12 06:32:01 +0000
+++ cronscripts/request_daily_builds.py	2010-12-20 01:48:17 +0000
@@ -34,7 +34,7 @@
     def main(self):
         globalErrorUtility.configure(self.name)
         source = getUtility(ISourcePackageRecipeBuildSource)
-        builds = source.makeDailyBuilds()
+        builds = source.makeDailyBuilds(self.logger)
         self.logger.info('Requested %d daily builds.' % len(builds))
         transaction.commit()
 

=== modified file 'lib/canonical/launchpad/scripts/logger.py'
--- lib/canonical/launchpad/scripts/logger.py	2010-10-22 10:23:17 +0000
+++ lib/canonical/launchpad/scripts/logger.py	2010-12-20 01:48:17 +0000
@@ -143,6 +143,10 @@
                 for line in thing.splitlines():
                     self.log(line)
 
+    def getLogOutput(self):
+        self.buffer.seek(0)
+        return self.buffer.readlines()
+
 
 class OopsHandler(logging.Handler):
     """Handler to log to the OOPS system."""

=== modified file 'lib/lp/code/interfaces/sourcepackagerecipebuild.py'
--- lib/lp/code/interfaces/sourcepackagerecipebuild.py	2010-11-11 20:56:21 +0000
+++ lib/lp/code/interfaces/sourcepackagerecipebuild.py	2010-12-20 01:48:17 +0000
@@ -98,8 +98,11 @@
         :return: `ISourcePackageRecipeBuild`.
         """
 
-    def makeDailyBuilds():
-        """Create and return builds for stale ISourcePackageRecipes."""
+    def makeDailyBuilds(logger=None):
+        """Create and return builds for stale ISourcePackageRecipes.
+
+        :param logger: An optional logger to write debug info to.
+        """
 
     def getById(build_id):
         """Return the `ISourcePackageRecipeBuild` for the given build id.

=== modified file 'lib/lp/code/model/sourcepackagerecipebuild.py'
--- lib/lp/code/model/sourcepackagerecipebuild.py	2010-11-30 12:23:01 +0000
+++ lib/lp/code/model/sourcepackagerecipebuild.py	2010-12-20 01:48:17 +0000
@@ -182,7 +182,7 @@
         return spbuild
 
     @staticmethod
-    def makeDailyBuilds():
+    def makeDailyBuilds(logger=None):
         from lp.code.model.sourcepackagerecipe import SourcePackageRecipe
         recipes = SourcePackageRecipe.findStaleDailyBuilds()
         builds = []
@@ -200,6 +200,10 @@
                     info = sys.exc_info()
                     errorlog.globalErrorUtility.raising(info)
                 else:
+                    if logger is not None:
+                        logger.debug(
+                            'Build for %s/%s requested',
+                            recipe.owner.name, recipe.name)
                     builds.append(build)
             recipe.is_stale = False
         return builds

=== modified file 'lib/lp/code/model/tests/test_sourcepackagerecipebuild.py'
--- lib/lp/code/model/tests/test_sourcepackagerecipebuild.py	2010-11-19 12:22:15 +0000
+++ lib/lp/code/model/tests/test_sourcepackagerecipebuild.py	2010-12-20 01:48:17 +0000
@@ -17,6 +17,7 @@
 from twisted.trial.unittest import TestCase as TrialTestCase
 
 from canonical.launchpad.interfaces.lpstorm import IStore
+from canonical.launchpad.scripts.logger import BufferLogger
 from canonical.launchpad.webapp.authorization import check_permission
 from canonical.launchpad.webapp.testing import verifyObject
 from canonical.testing.layers import (
@@ -235,6 +236,18 @@
         self.assertEqual(recipe, build.recipe)
         self.assertEqual(list(recipe.distroseries), [build.distroseries])
 
+    def test_makeDailyBuilds_logs_builds(self):
+        # If a logger is passed into the makeDailyBuilds method, each recipe
+        # that a build is requested for gets logged.
+        owner = self.factory.makePerson(name='eric')
+        self.factory.makeSourcePackageRecipe(
+            owner=owner, name=u'funky-recipe', build_daily=True)
+        logger = BufferLogger()
+        SourcePackageRecipeBuild.makeDailyBuilds(logger)
+        self.assertEqual(
+            ['DEBUG: Build for eric/funky-recipe requested\n'],
+            logger.getLogOutput())
+
     def test_makeDailyBuilds_clears_is_stale(self):
         recipe = self.factory.makeSourcePackageRecipe(
             build_daily=True, is_stale=True)

=== modified file 'lib/lp/testing/logger.py'
--- lib/lp/testing/logger.py	2010-07-12 13:06:41 +0000
+++ lib/lp/testing/logger.py	2010-12-20 01:48:17 +0000
@@ -4,7 +4,9 @@
 """Frequently-used logging utilities for test suite."""
 
 __metaclass__ = type
-__all__ = ['MockLogger']
+__all__ = [
+    'MockLogger',
+    ]
 
 import logging
 import sys