From a6ff771ab773e5214f46c1a86d8d829d74903e16 Mon Sep 17 00:00:00 2001 From: Steve Baker Date: Thu, 15 Oct 2015 13:30:19 +1300 Subject: [PATCH] Log all resource events during overcloud deploy This change switches the overcloud deploy stack polling with event list polling. This uses the same technique as the recently added heat stack-create --poll mode: Ib7d35b66521f0ccca8544fd18fb70e04eaf98e5a There is a (CREATE|UPDATE)_(COMPLETE|FAILED) event generated when the stack operation is complete, so this is used to decide when to stop polling. Also, every time there is an event it is printed to the screen in log style. This would give the user an indication that something is happening, which is better than staring at nothing for minutes (hours). On stack update, the oldest event from the previous operation is discovered and that is used for the marker so that only new events are logged. Change-Id: I8951b0b924db769961aa67e654fcbd774d3e7787 --- requirements.txt | 2 +- tripleoclient/tests/test_utils.py | 67 ++++++++++++------ .../overcloud_deploy/test_overcloud_deploy.py | 17 ++++- tripleoclient/utils.py | 68 +++++++++++++++---- tripleoclient/v1/overcloud_deploy.py | 14 +++- 5 files changed, 127 insertions(+), 41 deletions(-) diff --git a/requirements.txt b/requirements.txt index e3b29ec11..5550ff333 100644 --- a/requirements.txt +++ b/requirements.txt @@ -9,7 +9,7 @@ ipaddress passlib>=1.6 python-ironic-inspector-client>=1.0.1 os-cloud-config -python-heatclient>=0.3.0 +python-heatclient>=0.6.0 python-ironicclient>=0.8.0 python-openstackclient>=1.5.0 six>=1.9.0 diff --git a/tripleoclient/tests/test_utils.py b/tripleoclient/tests/test_utils.py index fa69166a3..40e184fef 100644 --- a/tripleoclient/tests/test_utils.py +++ b/tripleoclient/tests/test_utils.py @@ -115,19 +115,36 @@ class TestCheckHypervisorUtil(TestCase): class TestWaitForStackUtil(TestCase): def setUp(self): self.mock_orchestration = mock.Mock() - self.mock_stacks = mock.MagicMock() - self.stack_status = mock.PropertyMock() - type(self.mock_stacks).stack_status = self.stack_status - self.mock_orchestration.stacks.get.return_value = self.mock_stacks + def mock_event(self, resource_name, id, resource_status_reason, + resource_status, event_time): + e = mock.Mock() + e.resource_name = resource_name + e.id = id + e.resource_status_reason = resource_status_reason + e.resource_status = resource_status + e.event_time = event_time + return e + + @mock.patch("heatclient.common.event_utils.get_events") @mock.patch('time.sleep', return_value=None) - def test_wait_for_stack_ready(self, sleep_mock): - self.mock_orchestration.reset_mock() - self.mock_stacks.reset_mock() + def test_wait_for_stack_ready(self, sleep_mock, mock_el): + stack = mock.Mock() + stack.stack_name = 'stack' + self.mock_orchestration.stacks.get.return_value = stack - return_values = ['CREATE_IN_PROGRESS', 'CREATE_COMPLETE'] - - self.stack_status.side_effect = return_values + mock_el.side_effect = [[ + self.mock_event('stack', 'aaa', 'Stack CREATE started', + 'CREATE_IN_PROGRESS', '2015-10-14T02:25:21Z'), + self.mock_event('thing', 'bbb', 'state changed', + 'CREATE_IN_PROGRESS', '2015-10-14T02:25:21Z'), + ], [ + self.mock_event('thing', 'ccc', 'state changed', + 'CREATE_COMPLETE', '2015-10-14T02:25:43Z'), + self.mock_event('stack', 'ddd', + 'Stack CREATE completed successfully', + 'CREATE_COMPLETE', '2015-10-14T02:25:43Z'), + ]] complete = utils.wait_for_stack_ready(self.mock_orchestration, 'stack') @@ -136,28 +153,36 @@ class TestWaitForStackUtil(TestCase): sleep_mock.assert_called_once_with(mock.ANY) def test_wait_for_stack_ready_no_stack(self): - self.mock_orchestration.reset_mock() - self.mock_orchestration.stacks.get.return_value = None complete = utils.wait_for_stack_ready(self.mock_orchestration, 'stack') - self.mock_orchestration.stacks.get.return_value = self.mock_stacks - self.assertFalse(complete) - def test_wait_for_stack_ready_failed(self): - self.mock_orchestration.reset_mock() - self.mock_stacks.reset_mock() - - return_values = ['CREATE_FAILED'] - - self.stack_status.side_effect = return_values + @mock.patch("heatclient.common.event_utils.get_events") + @mock.patch('time.sleep', return_value=None) + def test_wait_for_stack_ready_failed(self, sleep_mock, mock_el): + stack = mock.Mock() + stack.stack_name = 'stack' + self.mock_orchestration.stacks.get.return_value = stack + mock_el.side_effect = [[ + self.mock_event('stack', 'aaa', 'Stack CREATE started', + 'CREATE_IN_PROGRESS', '2015-10-14T02:25:21Z'), + self.mock_event('thing', 'bbb', 'state changed', + 'CREATE_IN_PROGRESS', '2015-10-14T02:25:21Z'), + ], [ + self.mock_event('thing', 'ccc', 'ouch', + 'CREATE_FAILED', '2015-10-14T02:25:43Z'), + self.mock_event('stack', 'ddd', 'ouch', + 'CREATE_FAILED', '2015-10-14T02:25:43Z'), + ]] complete = utils.wait_for_stack_ready(self.mock_orchestration, 'stack') self.assertFalse(complete) + sleep_mock.assert_called_once_with(mock.ANY) + class TestWaitForIntrospection(TestCase): diff --git a/tripleoclient/tests/v1/overcloud_deploy/test_overcloud_deploy.py b/tripleoclient/tests/v1/overcloud_deploy/test_overcloud_deploy.py index b35ebd52c..bb8b2c9cb 100644 --- a/tripleoclient/tests/v1/overcloud_deploy/test_overcloud_deploy.py +++ b/tripleoclient/tests/v1/overcloud_deploy/test_overcloud_deploy.py @@ -35,7 +35,9 @@ class TestDeployOvercloud(fakes.TestDeployOvercloud): super(TestDeployOvercloud, self).setUp() # Get the command object to test - self.cmd = overcloud_deploy.DeployOvercloud(self.app, None) + app_args = mock.Mock() + app_args.verbose_level = 1 + self.cmd = overcloud_deploy.DeployOvercloud(self.app, app_args) # mock validations for all deploy tests # for validator tests, see test_overcloud_deploy_validators.py @@ -51,6 +53,7 @@ class TestDeployOvercloud(fakes.TestDeployOvercloud): super(TestDeployOvercloud, self).tearDown() os.unlink(self.parameter_defaults_env_file) + @mock.patch("heatclient.common.event_utils.get_events") @mock.patch('tripleo_common.update.add_breakpoints_cleanup_into_env') @mock.patch('tripleoclient.v1.overcloud_deploy.DeployOvercloud.' '_create_parameters_env') @@ -92,7 +95,8 @@ class TestDeployOvercloud(fakes.TestDeployOvercloud): mock_create_tempest_deployer_input, mock_deploy_postconfig, mock_create_parameters_env, - mock_breakpoints_cleanup): + mock_breakpoints_cleanupm, + mock_events): arglist = ['--templates', '--ceph-storage-scale', '3'] verifylist = [ @@ -107,6 +111,9 @@ class TestDeployOvercloud(fakes.TestDeployOvercloud): clients = self.app.client_manager orchestration_client = clients.tripleoclient.orchestration() orchestration_client.stacks.get.return_value = fakes.create_tht_stack() + mock_event = mock.Mock() + mock_event.id = '1234' + mock_events.return_value = [mock_events] mock_check_hypervisor_stats.return_value = { 'count': 4, @@ -366,6 +373,7 @@ class TestDeployOvercloud(fakes.TestDeployOvercloud): mock_validate_args.assert_called_once_with(parsed_args) + @mock.patch("heatclient.common.event_utils.get_events") @mock.patch('tripleo_common.update.add_breakpoints_cleanup_into_env') @mock.patch('tripleoclient.v1.overcloud_deploy.DeployOvercloud.' '_deploy_postconfig') @@ -403,7 +411,8 @@ class TestDeployOvercloud(fakes.TestDeployOvercloud): mock_generate_overcloud_passwords, mock_create_tempest_deployer_input, mock_deploy_postconfig, - mock_breakpoints_cleanup): + mock_breakpoints_cleanup, + mock_events): arglist = ['--templates', '/home/stack/tripleo-heat-templates'] verifylist = [ @@ -415,6 +424,8 @@ class TestDeployOvercloud(fakes.TestDeployOvercloud): clients = self.app.client_manager orchestration_client = clients.tripleoclient.orchestration() orchestration_client.stacks.get.return_value = fakes.create_tht_stack() + orchestration_client.stacks.get.return_value = fakes.create_tht_stack() + mock_events.return_value = [] mock_check_hypervisor_stats.return_value = { 'count': 4, diff --git a/tripleoclient/utils.py b/tripleoclient/utils.py index 8a07da954..e1e746c2b 100644 --- a/tripleoclient/utils.py +++ b/tripleoclient/utils.py @@ -19,13 +19,13 @@ import json import logging import os import passlib.utils as passutils -import re import six import struct import subprocess import sys import time +from heatclient.common import event_utils from heatclient.exc import HTTPNotFound from six.moves import configparser from six.moves import urllib @@ -174,7 +174,8 @@ def check_hypervisor_stats(compute_client, nodes=1, memory=0, vcpu=0): return None -def wait_for_stack_ready(orchestration_client, stack_name): +def wait_for_stack_ready(orchestration_client, stack_name, marker=None, + action='CREATE', verbose=False): """Check the status of an orchestration stack Get the status of an orchestration stack and check whether it is complete @@ -185,26 +186,63 @@ def wait_for_stack_ready(orchestration_client, stack_name): :param stack_name: Name or UUID of stack to retrieve :type stack_name: string + + :param marker: UUID of the last stack event before the current action + :type marker: string + + :param action: Current action to check the stack for COMPLETE + :type action: string + + :param verbose: Whether to print events + :type verbose: boolean """ - SUCCESSFUL_MATCH_OUTPUT = "(CREATE|UPDATE)_COMPLETE" - FAIL_MATCH_OUTPUT = "(CREATE|UPDATE)_FAILED" + stack = get_stack(orchestration_client, stack_name) + if not stack: + return False + stack_name = stack.stack_name while True: - stack = orchestration_client.stacks.get(stack_name) + events = event_utils.get_events(orchestration_client, + stack_id=stack_name, nested_depth=2, + event_args={'sort_dir': 'asc', + 'marker': marker}) - if not stack: - return False + if len(events) >= 1: + # set marker to last event that was received. + marker = getattr(events[-1], 'id', None) - status = stack.stack_status + if verbose: + events_log = event_log_formatter(events) + print(events_log) + for event in events: + # check if stack event was also received + if getattr(event, 'resource_name', '') == stack_name: + stack_status = getattr(event, 'resource_status', '') + print("Stack %(name)s %(status)s" % dict( + name=stack_name, status=stack_status)) + if stack_status == '%s_COMPLETE' % action: + return True + elif stack_status == '%s_FAILED' % action: + return False + time.sleep(5) - if re.match(SUCCESSFUL_MATCH_OUTPUT, status): - return True - if re.match(FAIL_MATCH_OUTPUT, status): - print("Stack failed with status: {}".format( - stack.stack_status_reason, file=sys.stderr)) - return False - time.sleep(10) +def event_log_formatter(events): + """Return the events in log format.""" + event_log = [] + log_format = ("%(event_time)s " + "[%(rsrc_name)s]: %(rsrc_status)s %(rsrc_status_reason)s") + for event in events: + event_time = getattr(event, 'event_time', '') + log = log_format % { + 'event_time': event_time.replace('T', ' '), + 'rsrc_name': getattr(event, 'resource_name', ''), + 'rsrc_status': getattr(event, 'resource_status', ''), + 'rsrc_status_reason': getattr(event, 'resource_status_reason', '') + } + event_log.append(log) + + return "\n".join(event_log) def wait_for_provision_state(baremetal_client, node_uuid, provision_state, diff --git a/tripleoclient/v1/overcloud_deploy.py b/tripleoclient/v1/overcloud_deploy.py index 8f2cf6494..b28be7773 100644 --- a/tripleoclient/v1/overcloud_deploy.py +++ b/tripleoclient/v1/overcloud_deploy.py @@ -26,6 +26,7 @@ import tempfile import uuid from cliff import command +from heatclient.common import event_utils from heatclient.common import template_utils from openstackclient.common import exceptions as oscexc from openstackclient.common import utils as osc_utils @@ -248,15 +249,26 @@ class DeployOvercloud(command.Command): if stack is None: self.log.info("Performing Heat stack create") + action = 'CREATE' + marker = None orchestration_client.stacks.create(**stack_args) else: self.log.info("Performing Heat stack update") # Make sure existing parameters for stack are reused stack_args['existing'] = 'true' + # Find the last top-level event to use for the first marker + events = event_utils.get_events(orchestration_client, + stack_id=stack_name, + event_args={'sort_dir': 'desc', + 'limit': 1}) + marker = events[0].id if events else None + action = 'UPDATE' + orchestration_client.stacks.update(stack.id, **stack_args) + verbose_events = self.app_args.verbose_level > 0 create_result = utils.wait_for_stack_ready( - orchestration_client, stack_name) + orchestration_client, stack_name, marker, action, verbose_events) if not create_result: if stack is None: raise Exception("Heat Stack create failed.")