diff options
| -rwxr-xr-x | bin/cloud-init | 30 | ||||
| -rw-r--r-- | cloudinit/registry.py | 23 | ||||
| -rw-r--r-- | cloudinit/reporting.py | 201 | ||||
| -rw-r--r-- | cloudinit/sources/__init__.py | 40 | ||||
| -rw-r--r-- | cloudinit/stages.py | 10 | ||||
| -rw-r--r-- | tests/unittests/test_registry.py | 28 | ||||
| -rw-r--r-- | tests/unittests/test_reporting.py | 192 |
7 files changed, 512 insertions, 12 deletions
diff --git a/bin/cloud-init b/bin/cloud-init index 63c13b09..c808eda5 100755 --- a/bin/cloud-init +++ b/bin/cloud-init @@ -46,6 +46,7 @@ from cloudinit import sources from cloudinit import stages from cloudinit import templater from cloudinit import util +from cloudinit import reporting from cloudinit import version from cloudinit.settings import (PER_INSTANCE, PER_ALWAYS, PER_ONCE, @@ -171,7 +172,7 @@ def main_init(name, args): w_msg = welcome_format(name) else: w_msg = welcome_format("%s-local" % (name)) - init = stages.Init(deps) + init = stages.Init(ds_deps=deps, reporter=args.reporter) # Stage 1 init.read_cfg(extract_fns(args)) # Stage 2 @@ -313,7 +314,7 @@ def main_modules(action_name, args): # 5. Run the modules for the given stage name # 6. Done! w_msg = welcome_format("%s:%s" % (action_name, name)) - init = stages.Init(ds_deps=[]) + init = stages.Init(ds_deps=[], reporter=args.reporter) # Stage 1 init.read_cfg(extract_fns(args)) # Stage 2 @@ -549,6 +550,8 @@ def main(): ' found (use at your own risk)'), dest='force', default=False) + + parser.set_defaults(reporter=None) subparsers = parser.add_subparsers() # Each action and its sub-options (if any) @@ -595,6 +598,9 @@ def main(): help=("frequency of the module"), required=False, choices=list(FREQ_SHORT_NAMES.keys())) + parser_single.add_argument("--report", action="store_true", + help="enable reporting", + required=False) parser_single.add_argument("module_args", nargs="*", metavar='argument', help=('any additional arguments to' @@ -617,8 +623,24 @@ def main(): if name in ("modules", "init"): functor = status_wrapper - return util.log_time(logfunc=LOG.debug, msg="cloud-init mode '%s'" % name, - get_uptime=True, func=functor, args=(name, args)) + report_on = True + if name == "init": + if args.local: + rname, rdesc = ("init-local", "searching for local datasources") + else: + rname, rdesc = ("init-network", "searching for network datasources") + elif name == "modules": + rname, rdesc = ("modules-%s" % args.mode, "running modules for %s") + elif name == "single": + rname, rdesc = ("single/%s" % args.name, + "running single module %s" % args.name) + report_on = args.report + + args.reporter = reporting.ReportStack(rname, rdesc, reporting=report_on) + with args.reporter: + return util.log_time( + logfunc=LOG.debug, msg="cloud-init mode '%s'" % name, + get_uptime=True, func=functor, args=(name, args)) if __name__ == '__main__': diff --git a/cloudinit/registry.py b/cloudinit/registry.py new file mode 100644 index 00000000..46cf0585 --- /dev/null +++ b/cloudinit/registry.py @@ -0,0 +1,23 @@ +import copy + + +class DictRegistry(object): + """A simple registry for a mapping of objects.""" + + def __init__(self): + self._items = {} + + def register_item(self, key, item): + """Add item to the registry.""" + if key in self._items: + raise ValueError( + 'Item already registered with key {0}'.format(key)) + self._items[key] = item + + @property + def registered_items(self): + """All the items that have been registered. + + This cannot be used to modify the contents of the registry. + """ + return copy.copy(self._items) diff --git a/cloudinit/reporting.py b/cloudinit/reporting.py new file mode 100644 index 00000000..1bd7df0d --- /dev/null +++ b/cloudinit/reporting.py @@ -0,0 +1,201 @@ +# Copyright 2015 Canonical Ltd. +# This file is part of cloud-init. See LICENCE file for license information. +# +# vi: ts=4 expandtab +""" +cloud-init reporting framework + +The reporting framework is intended to allow all parts of cloud-init to +report events in a structured manner. +""" + +import abc +import logging + +from cloudinit.registry import DictRegistry + + +FINISH_EVENT_TYPE = 'finish' +START_EVENT_TYPE = 'start' + +DEFAULT_CONFIG = { + 'logging': {'type': 'log'}, + 'print': {'type': 'print'}, +} + + +class _nameset(set): + def __getattr__(self, name): + if name in self: + return name + raise AttributeError + +status = _nameset(("SUCCESS", "WARN", "FAIL")) + +instantiated_handler_registry = DictRegistry() +available_handlers = DictRegistry() + + +class ReportingEvent(object): + """Encapsulation of event formatting.""" + + def __init__(self, event_type, name, description): + self.event_type = event_type + self.name = name + self.description = description + + def as_string(self): + """The event represented as a string.""" + return '{0}: {1}: {2}'.format( + self.event_type, self.name, self.description) + + +class FinishReportingEvent(ReportingEvent): + + def __init__(self, name, description, result=None): + super(FinishReportingEvent, self).__init__( + FINISH_EVENT_TYPE, name, description) + if result is None: + result = status.SUCCESS + self.result = result + if result not in status: + raise ValueError("Invalid result: %s" % result) + + def as_string(self): + return '{0}: {1}: {2}: {3}'.format( + self.event_type, self.name, self.result, self.description) + + +class ReportingHandler(object): + + @abc.abstractmethod + def publish_event(self, event): + raise NotImplementedError + + +class LogHandler(ReportingHandler): + """Publishes events to the cloud-init log at the ``INFO`` log level.""" + + def publish_event(self, event): + """Publish an event to the ``INFO`` log level.""" + logger = logging.getLogger( + '.'.join([__name__, event.event_type, event.name])) + logger.info(event.as_string()) + + +class PrintHandler(ReportingHandler): + def publish_event(self, event): + print(event.as_string()) + + +def add_configuration(config): + for handler_name, handler_config in config.items(): + handler_config = handler_config.copy() + cls = available_handlers.registered_items[handler_config.pop('type')] + instance = cls(**handler_config) + instantiated_handler_registry.register_item(handler_name, instance) + + +def report_event(event): + """Report an event to all registered event handlers. + + This should generally be called via one of the other functions in + the reporting module. + + :param event_type: + The type of the event; this should be a constant from the + reporting module. + """ + for _, handler in instantiated_handler_registry.registered_items.items(): + handler.publish_event(event) + + +def report_finish_event(event_name, event_description, result): + """Report a "finish" event. + + See :py:func:`.report_event` for parameter details. + """ + event = FinishReportingEvent(event_name, event_description, result) + return report_event(event) + + +def report_start_event(event_name, event_description): + """Report a "start" event. + + :param event_name: + The name of the event; this should be a topic which events would + share (e.g. it will be the same for start and finish events). + + :param event_description: + A human-readable description of the event that has occurred. + """ + event = ReportingEvent(START_EVENT_TYPE, event_name, event_description) + return report_event(event) + + +class ReportStack(object): + def __init__(self, name, description, parent=None, reporting=None, + exc_result=None): + self.parent = parent + self.name = name + self.description = description + + if exc_result is None: + exc_result = status.FAIL + self.exc_result = exc_result + + # use parents reporting value if not provided + if reporting is None: + if parent: + reporting = parent.reporting + else: + reporting = True + self.reporting = reporting + + if parent: + self.fullname = '/'.join((parent.fullname, name,)) + else: + self.fullname = self.name + self.children = {} + + def __repr__(self): + return ("%s reporting=%s" % (self.fullname, self.reporting)) + + def __enter__(self): + self.exception = None + if self.reporting: + report_start_event(self.fullname, self.description) + if self.parent: + self.parent.children[self.name] = (None, None) + return self + + def childrens_finish_info(self, result=None, description=None): + for cand_result in (status.FAIL, status.WARN): + for name, (value, msg) in self.children.items(): + if value == cand_result: + return (value, "[" + name + "]" + msg) + if result is None: + result = status.SUCCESS + if description is None: + description = self.description + return (result, description) + + def finish_info(self, exc): + # return tuple of description, and value + if exc: + # by default, exceptions are fatal + return (self.exc_result, self.description) + return self.childrens_finish_info() + + def __exit__(self, exc_type, exc_value, traceback): + self.exception = exc_value + (result, msg) = self.finish_info(exc_value) + if self.parent: + self.parent.children[self.name] = (result, msg) + if self.reporting: + report_finish_event(self.fullname, msg, result) + + +available_handlers.register_item('log', LogHandler) +available_handlers.register_item('print', PrintHandler) +add_configuration(DEFAULT_CONFIG) diff --git a/cloudinit/sources/__init__.py b/cloudinit/sources/__init__.py index a21c08c2..c174a58f 100644 --- a/cloudinit/sources/__init__.py +++ b/cloudinit/sources/__init__.py @@ -27,6 +27,7 @@ import six from cloudinit import importer from cloudinit import log as logging +from cloudinit import reporting from cloudinit import type_utils from cloudinit import user_data as ud from cloudinit import util @@ -246,17 +247,44 @@ def normalize_pubkey_data(pubkey_data): return keys -def find_source(sys_cfg, distro, paths, ds_deps, cfg_list, pkg_list): +class SearchReportStack(reporting.ReportStack): + def __init__(self, source, ds_deps, parent): + self.source = source.replace("DataSource", "") + name = "check-%s" % self.source + self.found = False + self.mode = "network" if DEP_NETWORK in ds_deps else "local" + description = "searching for %s data from %s" % ( + self.mode, self.source) + super(SearchReportStack, self).__init__( + name=name, description=description, parent=parent, + exc_result=reporting.status.WARN) + + def finish_info(self, exc): + # return tuple of description, and value + if exc: + # by default, exceptions are fatal + return (self.exc_result, self.description) + if self.found: + description = "found %s data from %s" % (self.mode, self.source) + else: + description = "no %s data found from %s" % (self.mode, self.source) + return self.childrens_finish_info(description=description) + + +def find_source(sys_cfg, distro, paths, ds_deps, cfg_list, pkg_list, reporter): ds_list = list_sources(cfg_list, ds_deps, pkg_list) ds_names = [type_utils.obj_name(f) for f in ds_list] LOG.debug("Searching for data source in: %s", ds_names) - for cls in ds_list: + for i, cls in enumerate(ds_list): + srcname=ds_names[i] try: - LOG.debug("Seeing if we can get any data from %s", cls) - s = cls(sys_cfg, distro, paths) - if s.get_data(): - return (s, type_utils.obj_name(cls)) + with SearchReportStack(srcname, ds_deps, reporter) as rep: + LOG.debug("Seeing if we can get any data from %s", cls) + s = cls(sys_cfg, distro, paths) + if s.get_data(): + rep.found = True + return (s, type_utils.obj_name(cls)) except Exception: util.logexc(LOG, "Getting data from %s failed", cls) diff --git a/cloudinit/stages.py b/cloudinit/stages.py index d28e765b..2bf7a1c4 100644 --- a/cloudinit/stages.py +++ b/cloudinit/stages.py @@ -46,6 +46,7 @@ from cloudinit import log as logging from cloudinit import sources from cloudinit import type_utils from cloudinit import util +from cloudinit import reporting LOG = logging.getLogger(__name__) @@ -53,7 +54,7 @@ NULL_DATA_SOURCE = None class Init(object): - def __init__(self, ds_deps=None): + def __init__(self, ds_deps=None, reporter=None): if ds_deps is not None: self.ds_deps = ds_deps else: @@ -65,6 +66,11 @@ class Init(object): # Changed only when a fetch occurs self.datasource = NULL_DATA_SOURCE + if reporter is None: + reporter = reporting.ReportStack( + name="init-reporter", description="init-desc", reporting=False) + self.reporter = reporter + def _reset(self, reset_ds=False): # Recreated on access self._cfg = None @@ -246,7 +252,7 @@ class Init(object): self.paths, copy.deepcopy(self.ds_deps), cfg_list, - pkg_list) + pkg_list, self.reporter) LOG.info("Loaded datasource %s - %s", dsname, ds) self.datasource = ds # Ensure we adjust our path members datasource diff --git a/tests/unittests/test_registry.py b/tests/unittests/test_registry.py new file mode 100644 index 00000000..bcf01475 --- /dev/null +++ b/tests/unittests/test_registry.py @@ -0,0 +1,28 @@ +from cloudinit.registry import DictRegistry + +from .helpers import (mock, TestCase) + + +class TestDictRegistry(TestCase): + + def test_added_item_included_in_output(self): + registry = DictRegistry() + item_key, item_to_register = 'test_key', mock.Mock() + registry.register_item(item_key, item_to_register) + self.assertEqual({item_key: item_to_register}, + registry.registered_items) + + def test_registry_starts_out_empty(self): + self.assertEqual({}, DictRegistry().registered_items) + + def test_modifying_registered_items_isnt_exposed_to_other_callers(self): + registry = DictRegistry() + registry.registered_items['test_item'] = mock.Mock() + self.assertEqual({}, registry.registered_items) + + def test_keys_cannot_be_replaced(self): + registry = DictRegistry() + item_key = 'test_key' + registry.register_item(item_key, mock.Mock()) + self.assertRaises(ValueError, + registry.register_item, item_key, mock.Mock()) diff --git a/tests/unittests/test_reporting.py b/tests/unittests/test_reporting.py new file mode 100644 index 00000000..5700118f --- /dev/null +++ b/tests/unittests/test_reporting.py @@ -0,0 +1,192 @@ +# Copyright 2015 Canonical Ltd. +# This file is part of cloud-init. See LICENCE file for license information. +# +# vi: ts=4 expandtab + +from cloudinit import reporting + +from .helpers import (mock, TestCase) + + +def _fake_registry(): + return mock.Mock(registered_items={'a': mock.MagicMock(), + 'b': mock.MagicMock()}) + + +class TestReportStartEvent(TestCase): + + @mock.patch('cloudinit.reporting.instantiated_handler_registry', + new_callable=_fake_registry) + def test_report_start_event_passes_something_with_as_string_to_handlers( + self, instantiated_handler_registry): + event_name, event_description = 'my_test_event', 'my description' + reporting.report_start_event(event_name, event_description) + expected_string_representation = ': '.join( + ['start', event_name, event_description]) + for _, handler in ( + instantiated_handler_registry.registered_items.items()): + self.assertEqual(1, handler.publish_event.call_count) + event = handler.publish_event.call_args[0][0] + self.assertEqual(expected_string_representation, event.as_string()) + + +class TestReportFinishEvent(TestCase): + + def _report_finish_event(self, result=None): + event_name, event_description = 'my_test_event', 'my description' + reporting.report_finish_event( + event_name, event_description, result=result) + return event_name, event_description + + def assertHandlersPassedObjectWithAsString( + self, handlers, expected_as_string): + for _, handler in handlers.items(): + self.assertEqual(1, handler.publish_event.call_count) + event = handler.publish_event.call_args[0][0] + self.assertEqual(expected_as_string, event.as_string()) + + @mock.patch('cloudinit.reporting.instantiated_handler_registry', + new_callable=_fake_registry) + def test_report_finish_event_passes_something_with_as_string_to_handlers( + self, instantiated_handler_registry): + event_name, event_description = self._report_finish_event() + expected_string_representation = ': '.join( + ['finish', event_name, reporting.status.SUCCESS, event_description]) + self.assertHandlersPassedObjectWithAsString( + instantiated_handler_registry.registered_items, + expected_string_representation) + + @mock.patch('cloudinit.reporting.instantiated_handler_registry', + new_callable=_fake_registry) + def test_reporting_successful_finish_has_sensible_string_repr( + self, instantiated_handler_registry): + event_name, event_description = self._report_finish_event( + result=reporting.status.SUCCESS) + expected_string_representation = ': '.join( + ['finish', event_name, reporting.status.SUCCESS, event_description]) + self.assertHandlersPassedObjectWithAsString( + instantiated_handler_registry.registered_items, + expected_string_representation) + + @mock.patch('cloudinit.reporting.instantiated_handler_registry', + new_callable=_fake_registry) + def test_reporting_unsuccessful_finish_has_sensible_string_repr( + self, instantiated_handler_registry): + event_name, event_description = self._report_finish_event( + result=reporting.status.FAIL) + expected_string_representation = ': '.join( + ['finish', event_name, reporting.status.FAIL, event_description]) + self.assertHandlersPassedObjectWithAsString( + instantiated_handler_registry.registered_items, + expected_string_representation) + + +class TestReportingEvent(TestCase): + + def test_as_string(self): + event_type, name, description = 'test_type', 'test_name', 'test_desc' + event = reporting.ReportingEvent(event_type, name, description) + expected_string_representation = ': '.join( + [event_type, name, description]) + self.assertEqual(expected_string_representation, event.as_string()) + + +class TestReportingHandler(TestCase): + + def test_no_default_publish_event_implementation(self): + self.assertRaises(NotImplementedError, + reporting.ReportingHandler().publish_event, None) + + +class TestLogHandler(TestCase): + + @mock.patch.object(reporting.logging, 'getLogger') + def test_appropriate_logger_used(self, getLogger): + event_type, event_name = 'test_type', 'test_name' + event = reporting.ReportingEvent(event_type, event_name, 'description') + reporting.LogHandler().publish_event(event) + self.assertEqual( + [mock.call( + 'cloudinit.reporting.{0}.{1}'.format(event_type, event_name))], + getLogger.call_args_list) + + @mock.patch.object(reporting.logging, 'getLogger') + def test_single_log_message_at_info_published(self, getLogger): + event = reporting.ReportingEvent('type', 'name', 'description') + reporting.LogHandler().publish_event(event) + self.assertEqual(1, getLogger.return_value.info.call_count) + + @mock.patch.object(reporting.logging, 'getLogger') + def test_log_message_uses_event_as_string(self, getLogger): + event = reporting.ReportingEvent('type', 'name', 'description') + reporting.LogHandler().publish_event(event) + self.assertIn(event.as_string(), + getLogger.return_value.info.call_args[0][0]) + + +class TestDefaultRegisteredHandler(TestCase): + + def test_log_handler_registered_by_default(self): + registered_items = ( + reporting.instantiated_handler_registry.registered_items) + for _, item in registered_items.items(): + if isinstance(item, reporting.LogHandler): + break + else: + self.fail('No reporting LogHandler registered by default.') + + +class TestReportingConfiguration(TestCase): + + @mock.patch.object(reporting, 'instantiated_handler_registry') + def test_empty_configuration_doesnt_add_handlers( + self, instantiated_handler_registry): + reporting.add_configuration({}) + self.assertEqual( + 0, instantiated_handler_registry.register_item.call_count) + + @mock.patch.object( + reporting, 'instantiated_handler_registry', reporting.DictRegistry()) + @mock.patch.object(reporting, 'available_handlers') + def test_looks_up_handler_by_type_and_adds_it(self, available_handlers): + handler_type_name = 'test_handler' + handler_cls = mock.Mock() + available_handlers.registered_items = {handler_type_name: handler_cls} + handler_name = 'my_test_handler' + reporting.add_configuration( + {handler_name: {'type': handler_type_name}}) + self.assertEqual( + {handler_name: handler_cls.return_value}, + reporting.instantiated_handler_registry.registered_items) + + @mock.patch.object( + reporting, 'instantiated_handler_registry', reporting.DictRegistry()) + @mock.patch.object(reporting, 'available_handlers') + def test_uses_non_type_parts_of_config_dict_as_kwargs( + self, available_handlers): + handler_type_name = 'test_handler' + handler_cls = mock.Mock() + available_handlers.registered_items = {handler_type_name: handler_cls} + extra_kwargs = {'foo': 'bar', 'bar': 'baz'} + handler_config = extra_kwargs.copy() + handler_config.update({'type': handler_type_name}) + handler_name = 'my_test_handler' + reporting.add_configuration({handler_name: handler_config}) + self.assertEqual( + handler_cls.return_value, + reporting.instantiated_handler_registry.registered_items[ + handler_name]) + self.assertEqual([mock.call(**extra_kwargs)], + handler_cls.call_args_list) + + @mock.patch.object( + reporting, 'instantiated_handler_registry', reporting.DictRegistry()) + @mock.patch.object(reporting, 'available_handlers') + def test_handler_config_not_modified(self, available_handlers): + handler_type_name = 'test_handler' + handler_cls = mock.Mock() + available_handlers.registered_items = {handler_type_name: handler_cls} + handler_config = {'type': handler_type_name, 'foo': 'bar'} + expected_handler_config = handler_config.copy() + reporting.add_configuration({'my_test_handler': handler_config}) + self.assertEqual(expected_handler_config, handler_config) |