Add --verbose-update-params option to heat-manage

In case the "heat-manage update-params" utility hangs in the middle of
a run, it is useful to know the exact raw_template or resource that
was being processed. Verbose logging of each raw_template or resource
that is being processed will aid in debugging and checking for corrupt
data (if the heat-manage process has to be killed).

Change-Id: Ic552bdaf234c7b9a6a76c345aab816a171b404ab
This commit is contained in:
Jason Dunsmore 2016-05-02 16:31:55 -05:00
parent 0fb2e0f43f
commit 59084fa24e
4 changed files with 119 additions and 8 deletions

View File

@ -108,9 +108,11 @@ def do_crypt_parameters_and_properties():
ctxt = context.get_admin_context()
prev_encryption_key = CONF.command.previous_encryption_key
if CONF.command.crypt_operation == "encrypt":
utils.encrypt_parameters_and_properties(ctxt, prev_encryption_key)
utils.encrypt_parameters_and_properties(
ctxt, prev_encryption_key, CONF.command.verbose_update_params)
elif CONF.command.crypt_operation == "decrypt":
utils.decrypt_parameters_and_properties(ctxt, prev_encryption_key)
utils.decrypt_parameters_and_properties(
ctxt, prev_encryption_key, CONF.command.verbose_update_params)
def add_command_parsers(subparsers):
@ -151,6 +153,9 @@ def add_command_parsers(subparsers):
default=None,
help=_('Provide old encryption key. New encryption'
' key would be used from config file.'))
parser.add_argument('--verbose-update-params', action='store_true',
help=_('Print an INFO message when processing of each '
'raw_template or resource begins or ends'))
parser = subparsers.add_parser('resource_data_list')
parser.set_defaults(func=do_resource_data_list)

View File

@ -35,6 +35,7 @@ from heat.common import crypt
from heat.common import exception
from heat.common.i18n import _
from heat.common.i18n import _LE
from heat.common.i18n import _LI
from heat.db.sqlalchemy import filters as db_filters
from heat.db.sqlalchemy import migration
from heat.db.sqlalchemy import models
@ -1224,7 +1225,8 @@ def db_version(engine):
return migration.db_version(engine)
def db_encrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
def db_encrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50,
verbose=False):
"""Encrypt parameters and properties for all templates in db.
:param ctxt: RPC context
@ -1233,6 +1235,8 @@ def db_encrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
:param batch_size: number of templates requested from db in each iteration.
50 means that heat requests 50 templates, encrypt them
and proceed with next 50 items.
:param verbose: log an INFO message when processing of each raw_template or
resource begins or ends
:return: list of exceptions encountered during encryption
"""
from heat.engine import template
@ -1244,6 +1248,9 @@ def db_encrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
session=session, ctxt=ctxt, query=query,
model=models.RawTemplate, batch_size=batch_size):
try:
if verbose:
LOG.info(_LI("Processing raw_template %(id)d..."),
{'id': raw_template.id})
tmpl = template.Template.load(
ctxt, raw_template.id, raw_template)
param_schemata = tmpl.param_schemata()
@ -1277,6 +1284,10 @@ def db_encrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
'template %(id)d'), {'id': raw_template.id})
excs.append(exc)
continue
finally:
if verbose:
LOG.info(_LI("Finished processing raw_template "
"%(id)d."), {'id': raw_template.id})
query = session.query(models.Resource).filter(
~models.Resource.properties_data.is_(None),
@ -1285,6 +1296,9 @@ def db_encrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
session=session, ctxt=ctxt, query=query, model=models.Resource,
batch_size=batch_size):
try:
if verbose:
LOG.info(_LI("Processing resource %(id)d..."),
{'id': resource.id})
result = {}
if not resource.properties_data:
continue
@ -1304,10 +1318,16 @@ def db_encrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
'resource %(id)d'), {'id': resource.id})
excs.append(exc)
continue
finally:
if verbose:
LOG.info(_LI("Finished processing resource "
"%(id)d."), {'id': resource.id})
return excs
def db_decrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
def db_decrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50,
verbose=False):
"""Decrypt parameters and properties for all templates in db.
:param ctxt: RPC context
@ -1316,6 +1336,8 @@ def db_decrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
:param batch_size: number of templates requested from db in each iteration.
50 means that heat requests 50 templates, encrypt them
and proceed with next 50 items.
:param verbose: log an INFO message when processing of each raw_template or
resource begins or ends
:return: list of exceptions encountered during decryption
"""
session = get_session()
@ -1326,6 +1348,9 @@ def db_decrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
session=session, ctxt=ctxt, query=query,
model=models.RawTemplate, batch_size=batch_size):
try:
if verbose:
LOG.info(_LI("Processing raw_template %(id)d..."),
{'id': raw_template.id})
parameters = raw_template.environment['parameters']
encrypted_params = raw_template.environment[
'encrypted_param_names']
@ -1344,6 +1369,10 @@ def db_decrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
'template %(id)d'), {'id': raw_template.id})
excs.append(exc)
continue
finally:
if verbose:
LOG.info(_LI("Finished processing raw_template "
"%(id)d."), {'id': raw_template.id})
query = session.query(models.Resource).filter(
~models.Resource.properties_data.is_(None),
@ -1352,6 +1381,9 @@ def db_decrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
session=session, ctxt=ctxt, query=query, model=models.Resource,
batch_size=batch_size):
try:
if verbose:
LOG.info(_LI("Processing resource %(id)d..."),
{'id': resource.id})
result = {}
for prop_name, prop_value in resource.properties_data.items():
method, value = prop_value
@ -1370,6 +1402,10 @@ def db_decrypt_parameters_and_properties(ctxt, encryption_key, batch_size=50):
'resource %(id)d'), {'id': resource.id})
excs.append(exc)
continue
finally:
if verbose:
LOG.info(_LI("Finished processing resource "
"%(id)d."), {'id': resource.id})
return excs

View File

@ -47,9 +47,11 @@ def purge_deleted(age, granularity='days'):
IMPL.purge_deleted(age, granularity)
def encrypt_parameters_and_properties(ctxt, encryption_key):
IMPL.db_encrypt_parameters_and_properties(ctxt, encryption_key)
def encrypt_parameters_and_properties(ctxt, encryption_key, verbose):
IMPL.db_encrypt_parameters_and_properties(ctxt, encryption_key,
verbose=verbose)
def decrypt_parameters_and_properties(ctxt, encryption_key):
IMPL.db_decrypt_parameters_and_properties(ctxt, encryption_key)
def decrypt_parameters_and_properties(ctxt, encryption_key, verbose):
IMPL.db_decrypt_parameters_and_properties(ctxt, encryption_key,
verbose=verbose)

View File

@ -12,7 +12,9 @@
# under the License.
import datetime
import fixtures
import json
import logging
import time
import uuid
@ -3205,6 +3207,72 @@ class DBAPICryptParamsPropsTest(common.HeatTestCase):
self.assertEqual([], db_api.db_encrypt_parameters_and_properties(
ctx, cfg.CONF.auth_encryption_key))
def test_db_encrypt_decrypt_verbose_on(self):
info_logger = self.useFixture(
fixtures.FakeLogger(level=logging.INFO,
format="%(levelname)8s [%(name)s] %("
"message)s"))
ctx = utils.dummy_context()
template = self._create_template()
user_creds = create_user_creds(ctx)
stack = create_stack(ctx, template, user_creds)
create_resource(ctx, stack, name='res1')
db_api.db_encrypt_parameters_and_properties(
ctx, cfg.CONF.auth_encryption_key, verbose=True)
self.assertIn("Processing raw_template 1", info_logger.output)
self.assertIn("Processing resource 1", info_logger.output)
self.assertIn("Finished processing raw_template 1",
info_logger.output)
self.assertIn("Finished processing resource 1", info_logger.output)
info_logger2 = self.useFixture(
fixtures.FakeLogger(level=logging.INFO,
format="%(levelname)8s [%(name)s] %("
"message)s"))
db_api.db_decrypt_parameters_and_properties(
ctx, cfg.CONF.auth_encryption_key, verbose=True)
self.assertIn("Processing raw_template 1", info_logger2.output)
self.assertIn("Processing resource 1", info_logger2.output)
self.assertIn("Finished processing raw_template 1",
info_logger2.output)
self.assertIn("Finished processing resource 1", info_logger2.output)
def test_db_encrypt_decrypt_verbose_off(self):
info_logger = self.useFixture(
fixtures.FakeLogger(level=logging.INFO,
format="%(levelname)8s [%(name)s] %("
"message)s"))
ctx = utils.dummy_context()
template = self._create_template()
user_creds = create_user_creds(ctx)
stack = create_stack(ctx, template, user_creds)
create_resource(ctx, stack, name='res1')
db_api.db_encrypt_parameters_and_properties(
ctx, cfg.CONF.auth_encryption_key, verbose=False)
self.assertNotIn("Processing raw_template 1", info_logger.output)
self.assertNotIn("Processing resource 1", info_logger.output)
self.assertNotIn("Successfully processed raw_template 1",
info_logger.output)
self.assertNotIn("Successfully processed resource 1",
info_logger.output)
info_logger2 = self.useFixture(
fixtures.FakeLogger(level=logging.INFO,
format="%(levelname)8s [%(name)s] %("
"message)s"))
db_api.db_decrypt_parameters_and_properties(
ctx, cfg.CONF.auth_encryption_key, verbose=False)
self.assertNotIn("Processing raw_template 1", info_logger2.output)
self.assertNotIn("Processing resource 1", info_logger2.output)
self.assertNotIn("Successfully processed raw_template 1",
info_logger2.output)
self.assertNotIn("Successfully processed resource 1",
info_logger2.output)
def test_db_encrypt_non_string_param_type(self):
t = template_format.parse('''
heat_template_version: 2013-05-23