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
This commit is contained in:
Steve Baker 2015-10-15 13:30:19 +13:00
parent 5c4bd5a81c
commit a6ff771ab7
5 changed files with 127 additions and 41 deletions

View File

@ -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

View File

@ -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):

View File

@ -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,

View File

@ -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,

View File

@ -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.")