cloud-init-dev team mailing list archive
-
cloud-init-dev team
-
Mailing list archive
-
Message #00719
[Merge] lp:~smoser/cloud-init/trunk.reporting into lp:cloud-init
Scott Moser has proposed merging lp:~smoser/cloud-init/trunk.reporting into lp:cloud-init.
Requested reviews:
cloud init development team (cloud-init-dev)
For more details, see:
https://code.launchpad.net/~smoser/cloud-init/trunk.reporting/+merge/266578
This is a backport of the 2.0 reporting code + some changes.
I'm interested in comments on changes to the 2.0 reporting code, and also in the general usage of 'reporting' from 0.7.
the goal will be to get whatever changes we find into 2.0 and then back into 0.7.x
--
Your team cloud init development team is requested to review the proposed merge of lp:~smoser/cloud-init/trunk.reporting into lp:cloud-init.
=== modified file 'bin/cloud-init'
--- bin/cloud-init 2015-07-31 02:06:31 +0000
+++ bin/cloud-init 2015-07-31 14:49:49 +0000
@@ -46,6 +46,7 @@
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 @@
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 @@
# 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
@@ -506,7 +507,11 @@
except Exception as e:
util.logexc(LOG, "failed of stage %s", mode)
+<<<<<<< TREE
print_exc("failed run of stage %s" mode)
+=======
+ print_exc("failed run of stage %s" % mode)
+>>>>>>> MERGE-SOURCE
v1[mode]['errors'] = [str(e)]
v1[mode]['finished'] = time.time()
@@ -549,6 +554,8 @@
' 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 +602,9 @@
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 +627,24 @@
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__':
=== added file 'cloudinit/registry.py'
--- cloudinit/registry.py 1970-01-01 00:00:00 +0000
+++ cloudinit/registry.py 2015-07-31 14:49:49 +0000
@@ -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)
=== added file 'cloudinit/reporting.py'
--- cloudinit/reporting.py 1970-01-01 00:00:00 +0000
+++ cloudinit/reporting.py 2015-07-31 14:49:49 +0000
@@ -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)
=== modified file 'cloudinit/sources/__init__.py'
--- cloudinit/sources/__init__.py 2015-07-22 12:06:34 +0000
+++ cloudinit/sources/__init__.py 2015-07-31 14:49:49 +0000
@@ -27,6 +27,7 @@
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,23 @@
return keys
-def find_source(sys_cfg, distro, paths, ds_deps, cfg_list, pkg_list):
+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):
+ name=ds_names[i].replace("DataSource", "")
+ myreporter = reporting.ReportStack(
+ "check-%s" % name, "searching for %s" % name,
+ parent=reporter, exc_result=reporting.status.WARN)
+
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 myreporter:
+ 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))
except Exception:
util.logexc(LOG, "Getting data from %s failed", cls)
=== modified file 'cloudinit/stages.py'
--- cloudinit/stages.py 2015-03-04 17:42:34 +0000
+++ cloudinit/stages.py 2015-07-31 14:49:49 +0000
@@ -46,6 +46,7 @@
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 @@
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 @@
# 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 @@
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
=== added file 'tests/unittests/test_registry.py'
--- tests/unittests/test_registry.py 1970-01-01 00:00:00 +0000
+++ tests/unittests/test_registry.py 2015-07-31 14:49:49 +0000
@@ -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())
=== added file 'tests/unittests/test_reporting.py'
--- tests/unittests/test_reporting.py 1970-01-01 00:00:00 +0000
+++ tests/unittests/test_reporting.py 2015-07-31 14:49:49 +0000
@@ -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)
Follow ups
