autotest/factory: improve message feedback on UI

client/cros/gooftools.py

Index: client/cros/gooftools.py
diff --git a/client/cros/gooftools.py b/client/cros/gooftools.py
index b3dbdcc3bf11f1b174be31e58aeaf1f9079da0b0..c8f07ab7c587fa73f6e6a031614948b3b47db68c 100644
--- a/client/cros/gooftools.py
+++ b/client/cros/gooftools.py
@@ -29,40 +29,56 @@ def run(command, ignore_status=False):
         command: Shell command to execute.
         ignore_status: False to raise exectopion when execution result is not 0.
 
+    Returns:
+        (stdout, stderr, return_code) of the execution results.
+
     Raises:
         error.TestError: The error message in "ERROR:.*" form by command.
     """
-    # prepare command
-    system_cmd = 'PATH="%s:$PATH" %s' % (GOOFTOOL_HOME, command)
-    factory.log("Running gooftool: " + system_cmd)
 
-    # prepare execution environment
+    factory.log("Running gooftool: " + command)
+
+    # We want the stderr goes to CONSOLE_LOG_PATH immediately, but tee only
+    # works with stdout; so here's a tiny trick to swap the handles.
+    swap_stdout_stderr = '3>&1 1>&2 2>&3'
+
+    # When using pipes, return code is from the last command; so we need to use
+    # a temporary file for the return code of first command.
+    return_code_file = tempfile.NamedTemporaryFile()
+    system_cmd = ('(PATH=%s:$PATH %s %s || echo $? >"%s") | tee -a "%s"' %
+                  (GOOFTOOL_HOME, command, swap_stdout_stderr,
+                   return_code_file.name, factory.CONSOLE_LOG_PATH))
     proc = subprocess.Popen(system_cmd,
                             stderr=subprocess.PIPE,
                             stdout=subprocess.PIPE,
                             shell=True)
-    (out, err) = proc.communicate()
+
+    # The order of output is reversed because we swapped stdout and stderr.
+    (err, out) = proc.communicate()
 
     # normalize output data
-    if out[-1:] == '\n':
+    out = out or ''
+    err = err or ''
+    if out.endswith('\n'):
         out = out[:-1]
-    err = err.strip()
-
-    if proc.wait() and (not ignore_status):
-        # log every detail.
-        out = out.strip()
-        if out or err:
-            message = '\n'.join([out, err])
-        else:
-            message = '(None)'
-        factory.log('gooftool execution failed, message: ' + message)
+    if err.endswith('\n'):
+        err = err[:-1]
+
+    # build return code and log results
+    return_code_file.seek(0)
+    return_code = int(return_code_file.read() or '0')
+    return_code_file.close()
+    return_code = proc.wait() or return_code
+    message = ('gooftool result: %s (%s), message: %s' %
+               (('FAILED' if return_code else 'SUCCESS'),
+                return_code, '\n'.join([out,err]) or '(None)'))
+    factory.log(message)
+
+    if return_code and (not ignore_status):
         # try to parse "ERROR.*" from err & out.
-        exception_message = [error_message for error_message in err.splitlines()
-                             if error_message.startswith('ERROR')]
-        exception_message = ('\n'.join(exception_message)
-                             if exception_message
-                             else 'Failed: %s\n%s\n%s' % (system_cmd, out, err))
+        exception_message = '\n'.join(
+                [error_message for error_message in err.splitlines()
+                 if error_message.startswith('ERROR')]) or message
         raise error.TestError(exception_message)
-    if out or err:
-        factory.log('gooftool results:\n%s\n%s' % (out, err))
-    return out
+
+    return (out, err, return_code)