Merge branch 'baserock/richardipsum/build-log-on-stdout-tee2'

Reviewed by:
    Lars Wirzenius
    Sam Thursfield
    Daniel Silverstone

6 files changed, 74 insertions, 26 deletions

diff --git a/distbuild/worker_build_scheduler.py b/distbuild/worker_build_scheduler.py
index 48ef4a7f..a61c50f7 100644
--- a/distbuild/worker_build_scheduler.py
+++ b/distbuild/worker_build_scheduler.py
@@ -468,6 +468,7 @@ class WorkerConnection(distbuild.StateMachine):
         argv = [
             self._morph_instance,
             'worker-build',
+            '--build-log-on-stdout',
             self._job.artifact.name,
         ]
         msg = distbuild.message('exec-request',
diff --git a/morphlib/app.py b/morphlib/app.py
index 91647a32..5b11d269 100644
--- a/morphlib/app.py
+++ b/morphlib/app.py
@@ -84,6 +84,9 @@ class Morph(cliapp.Application):
                               'do not update the cached git repositories '
                               'automatically',
                               group=group_advanced)
+        self.settings.boolean(['build-log-on-stdout'],
+                              'write build log on stdout',
+                              group=group_advanced)
         self.settings.string_list(['repo-alias'],
                                   'list of URL prefix definitions, in the '
                                   'form: example=git://git.example.com/%s'
diff --git a/morphlib/builder2.py b/morphlib/builder2.py
index 02e8b485..f8969973 100644
--- a/morphlib/builder2.py
+++ b/morphlib/builder2.py
@@ -335,29 +335,41 @@ class ChunkBuilder(BuilderBase):
     def build_and_cache(self):  # pragma: no cover
         with self.build_watch('overall-build'):
 
-            builddir, destdir = \
-                self.staging_area.chroot_open(self.artifact.source,
-                                              self.setup_mounts)
-            log_name = None
+            builddir, destdir = self.staging_area.chroot_open(
+                self.artifact.source, self.setup_mounts)
+
+            stdout = (self.app.output
+                if self.app.settings['build-log-on-stdout'] else None)
+
+            cache = self.local_artifact_cache
+            logpath = cache.get_source_metadata_filename(
+                self.artifact.source, self.artifact.cache_key, 'build-log')
+
+            _, temppath = tempfile.mkstemp(dir=os.path.dirname(logpath))
+
             try:
                 self.get_sources(builddir)
-                with self.local_artifact_cache.put_source_metadata(
-                        self.artifact.source, self.artifact.cache_key,
-                        'build-log') as log:
-                    log_name = log.real_filename
-                    self.run_commands(builddir, destdir, log)
-                    self.create_devices(destdir)
+                self.run_commands(builddir, destdir, temppath, stdout)
+                self.create_devices(destdir)
+
+                os.rename(temppath, logpath)
             except BaseException, e:
                 logging.error('Caught exception: %s' % str(e))
                 logging.info('Cleaning up staging area')
                 self.staging_area.chroot_close()
-                if log_name:
-                    with open(log_name) as f:
+                if os.path.isfile(temppath):
+                    with open(temppath) as f:
                         for line in f:
                             logging.error('OUTPUT FROM FAILED BUILD: %s' %
                                           line.rstrip('\n'))
+
+                    os.rename(temppath, logpath)
+                else:
+                    logging.error("Couldn't find build log at %s", temppath)
+
                 self.staging_area.abort()
                 raise
+
             self.staging_area.chroot_close()
             built_artifacts = self.assemble_chunk_artifacts(destdir)
 
@@ -365,7 +377,8 @@ class ChunkBuilder(BuilderBase):
         return built_artifacts
 
 
-    def run_commands(self, builddir, destdir, logfile):  # pragma: no cover
+    def run_commands(self, builddir, destdir,
+                     logfilepath, stdout=None):  # pragma: no cover
         m = self.artifact.source.morphology
         bs = morphlib.buildsystem.lookup_build_system(m['build-system'])
 
@@ -392,8 +405,10 @@ class ChunkBuilder(BuilderBase):
                 key = '%s-commands' % step
                 cmds = m.get_commands(key)
                 if cmds:
-                    self.app.status(msg='Running %(key)s', key=key)
-                    logfile.write('# %s\n' % step)
+                    with open(logfilepath, 'a') as log:
+                        self.app.status(msg='Running %(key)s', key=key)
+                        log.write('# %s\n' % step)
+
                 for cmd in cmds:
                     if in_parallel:
                         max_jobs = self.artifact.source.morphology['max-jobs']
@@ -402,23 +417,31 @@ class ChunkBuilder(BuilderBase):
                         extra_env['MAKEFLAGS'] = '-j%s' % max_jobs
                     else:
                         extra_env['MAKEFLAGS'] = '-j1'
+
                     try:
+                        with open(logfilepath, 'a') as log:
+                            log.write('# # %s\n' % cmd)
+
                         # flushing is needed because writes from python and
                         # writes from being the output in Popen have different
                         # buffers, but flush handles both
-                        logfile.write('# # %s\n' % cmd)
-                        logfile.flush()
+                        if stdout:
+                            stdout.flush()
+
                         self.runcmd(['sh', '-c', cmd],
                                     extra_env=extra_env,
                                     cwd=relative_builddir,
-                                    stdout=logfile,
-                                    stderr=subprocess.STDOUT)
-                        logfile.flush()
+                                    stdout=stdout or subprocess.PIPE,
+                                    stderr=subprocess.STDOUT,
+                                    logfile=logfilepath)
+
+                        if stdout:
+                            stdout.flush()
                     except cliapp.AppException, e:
-                        logfile.flush()
-                        with open(logfile.name, 'r') as readlog:
-                            self.app.output.write("%s failed\n" % step)
-                            shutil.copyfileobj(readlog, self.app.output)
+                        if not stdout:
+                            with open(logfilepath, 'r') as log:
+                                self.app.output.write("%s failed\n" % step)
+                                shutil.copyfileobj(log, self.app.output)
                         raise e
 
     def write_system_integration_commands(self, destdir,
diff --git a/morphlib/localartifactcache.py b/morphlib/localartifactcache.py
index 341bbb56..4c7f7832 100644
--- a/morphlib/localartifactcache.py
+++ b/morphlib/localartifactcache.py
@@ -1,4 +1,4 @@
-# Copyright (C) 2012,2013  Codethink Limited
+# Copyright (C) 2012, 2013, 2014  Codethink Limited
 #
 # This program is free software; you can redistribute it and/or modify
 # it under the terms of the GNU General Public License as published by
@@ -88,6 +88,9 @@ class LocalArtifactCache(object):
         os.utime(filename, None)
         return open(filename)
 
+    def get_source_metadata_filename(self, source, cachekey, name):
+        return self._source_metadata_filename(source, cachekey, name)
+
     def get_source_metadata(self, source, cachekey, name):
         filename = self._source_metadata_filename(source, cachekey, name)
         os.utime(filename, None)
diff --git a/morphlib/localartifactcache_tests.py b/morphlib/localartifactcache_tests.py
index 18d20612..f400a645 100644
--- a/morphlib/localartifactcache_tests.py
+++ b/morphlib/localartifactcache_tests.py
@@ -60,6 +60,17 @@ class LocalArtifactCacheTests(unittest.TestCase):
         expected_name = self.tempfs.getsyspath(self.devel_artifact.basename())
         self.assertEqual(filename, expected_name)
 
+    def test_get_source_metadata_filename(self):
+        cache = morphlib.localartifactcache.LocalArtifactCache(self.tempfs)
+        artifact = self.devel_artifact
+        name = 'foobar'
+
+        filename = cache.get_source_metadata_filename(artifact.source,
+                                                      artifact.cache_key, name)
+        expected_name = self.tempfs.getsyspath('%s.%s' %
+                                               (artifact.cache_key, name))
+        self.assertEqual(filename, expected_name)
+
     def test_put_artifacts_and_check_whether_the_cache_has_them(self):
         cache = morphlib.localartifactcache.LocalArtifactCache(self.tempfs)
 
diff --git a/morphlib/stagingarea.py b/morphlib/stagingarea.py
index 61f9e660..124edabf 100644
--- a/morphlib/stagingarea.py
+++ b/morphlib/stagingarea.py
@@ -309,7 +309,14 @@ class StagingArea(object):
         real_argv += argv
 
         try:
-            return self._app.runcmd(real_argv, **kwargs)
+            if 'logfile' in kwargs and kwargs['logfile'] != None:
+                logfile = kwargs['logfile']
+                del kwargs['logfile']
+
+                teecmd = ['tee', '-a', logfile]
+                return self._app.runcmd(real_argv, teecmd, **kwargs)
+            else:
+                return self._app.runcmd(real_argv, **kwargs)
         except cliapp.AppException as e:
             raise cliapp.AppException('In staging area %s: running '
                                       'command \'%s\' failed.' %