Let scripts return some useful message about failure

This patch exports a new env var for the script, the $TH_RESULT_FILE. If
the launched script writes something into the file name specified in
that env var and if the content of that file doesn't appear to indicate
a successful build, the content of the file is used as summary message
sent back to Zuul.

Originally, this patch attempted to do a similar thing through reading
back stuff from the shell's output log and reporting the last line from
that output, but the two major disadvantages were the inclusion of
timestamps in the log output, and Python's enrichment of the log line
with timestamps. I pondered writing a custom Python's logging.Handler
which simply remembers the last message, but the required changes in
utils.execute_to_log appeared rather messy to my untrained eye.

The main driver behind this change is a need to differentiate from hard
build failures (where we don't get any build artifacts because the build
simply failed) from "mere" test failures. Yes, our (KDE) tests are still
sloppy, and we have a fair amount of broken test still around, which is
why this difference matters to us. The result field in Zuul is more or
less free-form, so this patch does not impose any restrictions about its
format, except the "cannot start with 'SUCCESS'" because that one is
indeed very, very special.

It can be seen in action at http://ci-logs.kde.flaska.net/matrix.html .

Change-Id: I48c29d2566da12b02dcf27a551a058ecc4a303d4

1 files changed, 13 insertions, 1 deletions

diff --git a/turbo_hipster/lib/models.py b/turbo_hipster/lib/models.py
index 3987733..78c599a 100644
--- a/turbo_hipster/lib/models.py
+++ b/turbo_hipster/lib/models.py
@@ -17,6 +17,7 @@ import copy
 import json
 import logging
 import os
+import tempfile
 import pkg_resources
 import socket
 import uuid
@@ -259,6 +260,7 @@ class ShellTask(Task):
         self.job_working_dir = None
         self.shell_output_log = None
         self.git_prep_log = None
+        self.output_summary = None
 
     def do_job_steps(self):
         self.log.info('Step 1: Setup environment')
@@ -289,6 +291,7 @@ class ShellTask(Task):
             self.job_results_dir,
             'shell_output.log'
         )
+        self.output_summary = tempfile.mkstemp()
         self.log.info('Working on node %s' % (os.uname()[1]))
 
     @common.task_step
@@ -358,6 +361,7 @@ class ShellTask(Task):
             env_args['TH_JOB_NAME'] = self.job.name[len('build:'):]
         else:
             env_args['TH_JOB_NAME'] = self.job.name
+        env_args['TH_RESULT_FILE'] = self.output_summary[1]
 
         self.script_return_code = utils.execute_to_log(
             cmd,
@@ -369,6 +373,10 @@ class ShellTask(Task):
     def _parse_and_check_results(self):
         if self.script_return_code > 0:
             self.success = False
+            with os.fdopen(self.output_summary[0]) as fp:
+                line = fp.readline().strip()
+                if len(line) and not line.startswith('SUCCESS'):
+                    self.messages.append(line)
             self.messages.append('Return code from test script was non-zero '
                                  '(%d)' % self.script_return_code)
 
@@ -376,7 +384,11 @@ class ShellTask(Task):
     def _handle_cleanup(self):
         """Handle and cleanup functions. Shutdown if requested to so that no
         further jobs are ran if the environment is dirty."""
-        pass
+
+        try:
+            os.remove(self.output_summary[1])
+        except OSError:
+            pass
 
     @common.task_step
     def _handle_results(self):