Merge "Explicitely print the result status of each playbook run" into feature/zuulv3

zuul/ansible/callback/zuul_stream.py

@@ -168,32 +168,8 @@ class CallbackModule(default.CallbackModule):
                 host=host.name,
                 filename=included_file._filename))
 
-    def _emit_playbook_banner(self):
-        # Get the hostvars from just one host - the vars we're looking for will
-        # be identical on all of them
-        hostvars = next(iter(self._play._variable_manager._hostvars.values()))
-        self._playbook_name = None
-
-        phase = hostvars.get('zuul_execution_phase', '')
-        playbook = hostvars.get('zuul_execution_canonical_name_and_path')
-        trusted = hostvars.get('zuul_execution_trusted')
-        trusted = 'trusted' if trusted == "True" else 'untrusted'
-        branch = hostvars.get('zuul_execution_branch')
-
-        if phase and phase != 'run':
-            phase = '{phase}-run'.format(phase=phase)
-        phase = phase.upper()
-
-        self._log("{phase} [{trusted} : {playbook}@{branch}]".format(
-            trusted=trusted, phase=phase, playbook=playbook, branch=branch))
-
     def v2_playbook_on_play_start(self, play):
         self._play = play
-
-        # We can't fill in this information until the first play
-        if self._playbook_name:
-            self._emit_playbook_banner()
-
         # Log an extra blank line to get space before each play
         self._log("")
 

zuul/executor/server.py

@@ -1740,6 +1740,37 @@ class AnsibleJob(object):
             self.RESULT_MAP[result], code))
         return result, code
 
+    def emitPlaybookBanner(self, playbook, step, phase, result=None):
+        # This is used to print a header and a footer, respectively at the
+        # beginning and the end of each playbook execution.
+        # We are doing it from the executor rather than from a callback because
+        # the parameters are not made available to the callback until it's too
+        # late.
+        phase = phase or ''
+        trusted = playbook.trusted
+        trusted = 'trusted' if trusted else 'untrusted'
+        branch = playbook.branch
+        playbook = playbook.canonical_name_and_path
+
+        if phase and phase != 'run':
+            phase = '{phase}-run'.format(phase=phase)
+        phase = phase.upper()
+
+        if result is not None:
+            result = self.RESULT_MAP[result]
+            msg = "{phase} {step} {result}: [{trusted} : {playbook}@{branch}]"
+            msg.format(phase=phase, step=step, result=result,
+                       trusted=trusted, playbook=playbook, branch=branch)
+        else:
+            msg = "{phase} {step}: [{trusted} : {playbook}@{branch}]"
+            msg.format(phase=phase, step=step, trusted=trusted,
+                       playbook=playbook, branch=branch)
+
+        with open(self.jobdir.job_output_file, 'a') as job_output:
+            job_output.write("{now} | {msg}".format(
+                now=datetime.datetime.now(),
+                msg=msg))
+
     def runAnsiblePlaybook(self, playbook, timeout, success=None,
                            phase=None, index=None):
         if self.executor_server.verbose:
@@ -1770,8 +1801,12 @@ class AnsibleJob(object):
         if self.executor_variables_file is not None:
             cmd.extend(['-e@%s' % self.executor_variables_file])
 
+        self.emitPlaybookBanner(playbook, 'START', phase)
+
         result, code = self.runAnsible(
             cmd=cmd, timeout=timeout, playbook=playbook)
         self.log.debug("Ansible complete, result %s code %s" % (
             self.RESULT_MAP[result], code))
+
+        self.emitPlaybookBanner(playbook, 'END', phase, result=result)
         return result, code