From d296098c054221c50ecf5b2f4e1caa814cce7cbd Mon Sep 17 00:00:00 2001
From: Clark Boylan <clark.boylan@gmail.com>
Date: Fri, 4 Jun 2021 11:42:02 -0700
Subject: [PATCH] Cleanup Zuul's stdout/stderr output

This is primarily an issue in the unittests, but we also cleanup a
problem with output in ansible package installation verification.

There are two types of issue we address here. The first is unittests
calling print(). We replace those with log.info() calls to keep this
information from adding noise to the stestr output. The second is
subprocess.run() not capturing output so it ends up on stdout/stderr. In
this case we update use of subprocess.run() to capture the output, then
log/error appropriately if the return code is not 0.

Change-Id: I22650bf9495d3fe71bdf4a2dec5d9b3f30116188
---
 tests/unit/test_executor.py  |  9 ++++++++-
 tests/unit/test_gerrit.py    |  2 +-
 tests/unit/test_scheduler.py |  2 +-
 zuul/lib/ansible.py          | 19 +++++++++++++++----
 4 files changed, 25 insertions(+), 7 deletions(-)

diff --git a/tests/unit/test_executor.py b/tests/unit/test_executor.py
index baca6e053e..4434b7605a 100644
--- a/tests/unit/test_executor.py
+++ b/tests/unit/test_executor.py
@@ -940,7 +940,14 @@ class TestExecutorExtraPackages(AnsibleZuulTestCase):
         for version in ansible_manager._supported_versions:
             command = [ansible_manager.getAnsibleCommand(version, 'pip'),
                        'uninstall', '-y', self.test_package]
-            subprocess.run(command)
+            # We want to error if the uninstall fails as the test below
+            # relies on the package not being installed to be properly
+            # exercised.
+            s = subprocess.run(command,
+                               stdout=subprocess.PIPE,
+                               stderr=subprocess.STDOUT)
+            self.log.info(s.stdout)
+            self.assertEqual(s.returncode, 0)
 
     @mock.patch('zuul.lib.ansible.ManagedAnsible.extra_packages',
                 new_callable=mock.PropertyMock)
diff --git a/tests/unit/test_gerrit.py b/tests/unit/test_gerrit.py
index ab090cbc01..79b2c66e57 100644
--- a/tests/unit/test_gerrit.py
+++ b/tests/unit/test_gerrit.py
@@ -544,7 +544,7 @@ class TestChecksApi(ZuulTestCase):
         self.executor_server.hold_jobs_in_build = False
         self.executor_server.release()
         self.waitUntilSettled()
-        print(A.checks_history)
+        self.log.info(A.checks_history)
         self.assertEqual(A.checks_history[3]['zuul:check']['state'],
                          'NOT_STARTED')
         self.assertEqual(A.checks_history[4]['zuul:check']['state'],
diff --git a/tests/unit/test_scheduler.py b/tests/unit/test_scheduler.py
index 6bbde2f451..28f8bc0f4f 100644
--- a/tests/unit/test_scheduler.py
+++ b/tests/unit/test_scheduler.py
@@ -6966,7 +6966,7 @@ class TestDependencyGraph(ZuulTestCase):
         self.assertHistory([])
         self.assertEqual(len(A.messages), 1)
         self.assertTrue('Job project-merge not defined' in A.messages[0])
-        print(A.messages)
+        self.log.info(A.messages)
 
     @simple_layout('layouts/soft-dependencies.yaml')
     def test_soft_dependencies(self):
diff --git a/zuul/lib/ansible.py b/zuul/lib/ansible.py
index c275b3dbba..0e4e416cda 100644
--- a/zuul/lib/ansible.py
+++ b/zuul/lib/ansible.py
@@ -231,7 +231,7 @@ class AnsibleManager:
         return result
 
     def _validate_packages(self, version):
-        result = True
+        result = False
         try:
             extra_packages = self._getAnsible(version).extra_packages
             python_package_check = \
@@ -240,11 +240,22 @@ class AnsibleManager:
 
             command = [self.getAnsibleCommand(version, 'python'),
                        '-c', python_package_check]
-            subprocess.run(command, check=True)
+            ret = subprocess.run(command,
+                                 stdout=subprocess.PIPE,
+                                 stderr=subprocess.STDOUT)
+            # We check manually so that we can log the stdout and stderr
+            # properly which aren't going to be available if we have
+            # subprocess.run() check and raise.
+            if ret.returncode != 0:
+                self.log.error(
+                    'Ansible version %s installation is missing packages' %
+                    version)
+                self.log.debug("Ansible package check output: %s", ret.stdout)
+            else:
+                result = True
         except Exception:
-            result = False
             self.log.exception(
-                'Ansible version %s installation is missing packages' %
+                'Exception checking Ansible version %s packages' %
                 version)
         return result