From b3cb85f1123b15c1ec4fafac9dcedc9381072a8b Mon Sep 17 00:00:00 2001
From: Stephen Finucane <sfinucan@redhat.com>
Date: Mon, 6 Dec 2021 10:24:15 +0000
Subject: [PATCH] tests: Improve logging for executed commands
We're seeing failures in a recently added tests,
'ServerTests.test_server_add_remove_volume' from
'openstackclient/tests/functional/compute/v2/test_server.py'. These
failures are likely the result of slow CI nodes, but we don't have
enough information in the CI logs to debug them. Starting logging the
various commands executed in tests so that we can see these logs if and
when tests fail.
Change-Id: I4584dc5e6343fe8c8544431a527d8c3c7e7b3c5b
Signed-off-by: Stephen Finucane <sfinucan@redhat.com>
---
openstackclient/tests/functional/base.py | 21 ++++++++----
.../functional/compute/v2/test_server.py | 33 ++++++++++++++-----
2 files changed, 40 insertions(+), 14 deletions(-)
diff --git a/openstackclient/tests/functional/base.py b/openstackclient/tests/functional/base.py
index 0ed7dff8c4..e89c5b9737 100644
--- a/openstackclient/tests/functional/base.py
+++ b/openstackclient/tests/functional/base.py
@@ -10,6 +10,7 @@
# License for the specific language governing permissions and limitations
# under the License.
+import logging
import os
import shlex
import subprocess
@@ -18,22 +19,30 @@ from tempest.lib.cli import output_parser
from tempest.lib import exceptions
import testtools
-
ADMIN_CLOUD = os.environ.get('OS_ADMIN_CLOUD', 'devstack-admin')
+LOG = logging.getLogger(__name__)
def execute(cmd, fail_ok=False, merge_stderr=False):
"""Executes specified command for the given action."""
+ LOG.debug('Executing: %s', cmd)
cmdlist = shlex.split(cmd)
stdout = subprocess.PIPE
stderr = subprocess.STDOUT if merge_stderr else subprocess.PIPE
+
proc = subprocess.Popen(cmdlist, stdout=stdout, stderr=stderr)
- result, result_err = proc.communicate()
- result = result.decode('utf-8')
+
+ result_out, result_err = proc.communicate()
+ result_out = result_out.decode('utf-8')
+ LOG.debug('stdout: %s', result_out)
+ LOG.debug('stderr: %s', result_err)
+
if not fail_ok and proc.returncode != 0:
- raise exceptions.CommandFailed(proc.returncode, cmd, result,
- result_err)
- return result
+ raise exceptions.CommandFailed(
+ proc.returncode, cmd, result_out, result_err,
+ )
+
+ return result_out
class TestCase(testtools.TestCase):
diff --git a/openstackclient/tests/functional/compute/v2/test_server.py b/openstackclient/tests/functional/compute/v2/test_server.py
index cf4bcbc2a9..0558ef6213 100644
--- a/openstackclient/tests/functional/compute/v2/test_server.py
+++ b/openstackclient/tests/functional/compute/v2/test_server.py
@@ -1195,19 +1195,19 @@ class ServerTests(common.ComputeTestCase):
def test_server_add_remove_volume(self):
volume_wait_for = volume_common.BaseVolumeTests.wait_for_status
- name = uuid.uuid4().hex
+ server_name = uuid.uuid4().hex
cmd_output = json.loads(self.openstack(
'server create -f json ' +
'--network private ' +
'--flavor ' + self.flavor_name + ' ' +
'--image ' + self.image_name + ' ' +
'--wait ' +
- name
+ server_name
))
self.assertIsNotNone(cmd_output['id'])
- self.assertEqual(name, cmd_output['name'])
- self.addCleanup(self.openstack, 'server delete --wait ' + name)
+ self.assertEqual(server_name, cmd_output['name'])
+ self.addCleanup(self.openstack, 'server delete --wait ' + server_name)
server_id = cmd_output['id']
volume_name = uuid.uuid4().hex
@@ -1225,7 +1225,7 @@ class ServerTests(common.ComputeTestCase):
cmd_output = json.loads(self.openstack(
'server add volume -f json ' +
- name + ' ' +
+ server_name + ' ' +
volume_name + ' ' +
'--tag bar'
))
@@ -1237,7 +1237,7 @@ class ServerTests(common.ComputeTestCase):
cmd_output = json.loads(self.openstack(
'server volume list -f json ' +
- name
+ server_name
))
self.assertEqual(volume_attachment_id, cmd_output[0]['ID'])
@@ -1245,8 +1245,25 @@ class ServerTests(common.ComputeTestCase):
self.assertEqual(volume_id, cmd_output[0]['Volume ID'])
volume_wait_for('volume', volume_name, 'in-use')
- self.openstack('server remove volume ' + name + ' ' + volume_name)
+
+ cmd_output = json.loads(self.openstack(
+ 'server event list -f json ' +
+ server_name
+ ))
+ self.assertEqual(2, len(cmd_output))
+ self.assertIn('attach_volume', {x['Action'] for x in cmd_output})
+
+ self.openstack(
+ 'server remove volume ' + server_name + ' ' + volume_name
+ )
volume_wait_for('volume', volume_name, 'available')
- raw_output = self.openstack('server volume list ' + name)
+ cmd_output = json.loads(self.openstack(
+ 'server event list -f json ' +
+ server_name
+ ))
+ self.assertEqual(3, len(cmd_output))
+ self.assertIn('detach_volume', {x['Action'] for x in cmd_output})
+
+ raw_output = self.openstack('server volume list ' + server_name)
self.assertEqual('\n', raw_output)