From 10b21a4e74948cd5edb6c0006acd81fbe3b0d34f Mon Sep 17 00:00:00 2001 From: Sandy Walsh Date: Fri, 12 Dec 2014 10:53:34 -0800 Subject: [PATCH] Non-EOD .exists usage checks. Also adds support for warnings. Will generate a compute.instance.exists.warnings event when there is something suspicious but not an actual error. Change-Id: I00f135b20917231a8cf3f603f0954f061de15410 --- tests/test_usage_handler.py | 61 +++++++++++++++++++++++- winchester/pipeline_handler.py | 84 ++++++++++++++++++++++++++++++---- 2 files changed, 135 insertions(+), 10 deletions(-) diff --git a/tests/test_usage_handler.py b/tests/test_usage_handler.py index af76003..9058894 100644 --- a/tests/test_usage_handler.py +++ b/tests/test_usage_handler.py @@ -189,12 +189,71 @@ class TestUsageHandler(unittest.TestCase): self.assertEquals("Error", f['error']) self.assertEquals("UX", f['error_code']) + def test_handle_events_warnings(self): + def fake_find_exists(events): + self.handler.warnings = ['one', 'two'] + return {'timestamp':'now', 'instance_id':'inst'} + env = {'stream_id': 123} + with mock.patch.object(self.handler, "_find_exists") as ex: + ex.side_effect = fake_find_exists + with mock.patch.object(self.handler, "_do_checks") as c: + events = self.handler.handle_events([], env) + self.assertEquals(2, len(events)) + self.assertEquals("compute.instance.exists.warnings", + events[0]['event_type']) + self.assertEquals("compute.instance.exists.verified", + events[1]['event_type']) + + def test_confirm_non_EOD_exists_no_events(self): + events = [] + self.assertEquals(len(self.handler.warnings), 0) + self.handler._confirm_non_EOD_exists(events) + self.assertEquals(len(self.handler.warnings), 0) + + def test_confirm_non_EOD_exists_no_interesting(self): + events = [{'event_type': 'foo'}] + self.assertEquals(len(self.handler.warnings), 0) + self.handler._confirm_non_EOD_exists(events) + self.assertEquals(len(self.handler.warnings), 0) + + def test_confirm_non_EOD_exists_no_exists(self): + events = [{'event_type': 'compute.instance.rebuild.start', + 'message_id': 'xxx'}] + self.assertEquals(len(self.handler.warnings), 0) + self.handler._confirm_non_EOD_exists(events) + self.assertEquals(len(self.handler.warnings), 1) + x = "Interesting" + self.assertEquals(self.handler.warnings[0][:len(x)], x) + + def test_confirm_non_EOD_exists_good(self): + events = [{'event_type': 'compute.instance.rebuild.start'}, + {'event_type': 'compute.instance.exists'}] + self.assertEquals(len(self.handler.warnings), 0) + with mock.patch.object(self.handler, "_is_non_EOD_exists") as eod: + with mock.patch.object(self.handler, "_verify_fields") as vf: + eod.return_value = True + self.handler._confirm_non_EOD_exists(events) + self.assertEquals(len(self.handler.warnings), 0) + + def test_confirm_non_EOD_exists_not_EOD(self): + events = [{'event_type': 'compute.instance.exists', + 'message_id': 'blah'}] + self.assertEquals(len(self.handler.warnings), 0) + with mock.patch.object(self.handler, "_is_non_EOD_exists") as eod: + with mock.patch.object(self.handler, "_verify_fields") as vf: + eod.return_value = True + self.handler._confirm_non_EOD_exists(events) + self.assertEquals(len(self.handler.warnings), 1) + x = "Non-EOD" + self.assertEquals(self.handler.warnings[0][:len(x)], x) + + @mock.patch.object(pipeline_handler.UsageHandler, '_confirm_non_EOD_exists') @mock.patch.object(pipeline_handler.UsageHandler, '_get_core_fields') @mock.patch.object(pipeline_handler.UsageHandler, '_extract_launched_at') @mock.patch.object(pipeline_handler.UsageHandler, '_find_events') @mock.patch.object(pipeline_handler.UsageHandler, '_confirm_launched_at') @mock.patch.object(pipeline_handler.UsageHandler, '_confirm_delete') - def test_do_check(self, cd, cla, fe, ela, gcf): + def test_do_check(self, cd, cla, fe, ela, gcf, cnee): fe.return_value = [1,2,3] self.handler._do_checks({}, []) diff --git a/winchester/pipeline_handler.py b/winchester/pipeline_handler.py index b4c4c1c..4fab47f 100644 --- a/winchester/pipeline_handler.py +++ b/winchester/pipeline_handler.py @@ -99,6 +99,22 @@ class UsageException(Exception): class UsageHandler(PipelineHandlerBase): + def __init__(self, **kw): + super(UsageHandler, self).__init__(**kw) + self.warnings = [] + + def _is_non_EOD_exists(self, event): + # For non-EOD .exists, we just check that the APB and APE are + # not 24hrs apart. We could check that it's not midnight, but + # could be possible (though unlikely). + # And, if we don't find any extras, don't error out ... + # we'll do that later. + apb = event.get('audit_period_beginning') + ape = event.get('audit_period_ending') + return (event['event_type'] == 'compute.instance.exists' + and apb and ape + and ape.date() != (apb.date() + datetime.timedelta(days=1))) + def _find_exists(self, events): exists = None @@ -132,6 +148,9 @@ class UsageHandler(PipelineHandlerBase): if event['event_type'] in interesting] def _find_events(self, events): + # We could easily end up with no events in final_set if + # there were no operations performed on an instance that day. + # We'll still get a .exists for every active instance though. interesting = ['compute.instance.rebuild.start', 'compute.instance.resize.prep.start', 'compute.instance.resize.revert.start', @@ -142,24 +161,20 @@ class UsageHandler(PipelineHandlerBase): 'compute.instance.resize.revert.end', 'compute.instance.rescue.end'] - # We could easily end up with no events in final_set if - # there were no operations performed on an instance that day. - # We'll still get a .exists for every active instance though. - return self._extract_interesting_events(events, interesting) def _find_deleted_events(self, events): interesting = ['compute.instance.delete.end'] return self._extract_interesting_events(events, interesting) - def _verify_fields(self, exists, launch, fields): + def _verify_fields(self, this, that, fields): for field in fields: - if field not in exists and field not in launch: + if field not in this and field not in that: continue - if exists[field] != launch[field]: + if this[field] != that[field]: raise UsageException("U2", "Conflicting '%s' values ('%s' != '%s')" - % (field, exists[field], launch[field])) + % (field, this[field], that[field])) def _confirm_delete(self, exists, deleted, fields): deleted_at = exists.get('deleted_at') @@ -214,21 +229,58 @@ class UsageHandler(PipelineHandlerBase): return ['launched_at', 'instance_flavor_id', 'tenant_id', 'os_architecture', 'os_version', 'os_distro'] + def _confirm_non_EOD_exists(self, events): + interesting = ['compute.instance.rebuild.start', + 'compute.instance.resize.prep.start', + 'compute.instance.rescue.start'] + + last_interesting = None + fields = ['launched_at', 'deleted_at'] + for event in events: + if event['event_type'] in interesting: + last_interesting = event + elif (event['event_type'] == 'compute.instance.exists' and + self._is_non_EOD_exists(event)): + if last_interesting: + self._verify_fields(last_interesting, event, fields) + last_interesting = None + else: + self.warnings.append("Non-EOD .exists found " + "(msg_id: %s) " + "with no parent event." % + event['message_id']) + + # We got an interesting event, but no related .exists. + if last_interesting: + self.warnings.append("Interesting event '%s' (msg_id: %s) " + "but no related non-EOD .exists record." % + (last_interesting['event_type'], + last_interesting['message_id'])) + def _do_checks(self, exists, events): core_fields = self._get_core_fields() delete_fields = ['launched_at', 'deleted_at'] + # Ensure all the important fields of the important events + # match with the EOD .exists values. self._extract_launched_at(exists) - deleted = self._find_deleted_events(events) for c in self._find_events(events): self._verify_fields(exists, c, core_fields) self._confirm_launched_at(exists, events) + + # Ensure the deleted_at value matches as well. + deleted = self._find_deleted_events(events) self._confirm_delete(exists, deleted, delete_fields) + # Check the non-EOD .exists records. They should + # appear after an interesting event. + self._confirm_non_EOD_exists(events) + def handle_events(self, events, env): self.env = env self.stream_id = env['stream_id'] + self.warnings = [] exists = None error = None @@ -255,6 +307,20 @@ class UsageHandler(PipelineHandlerBase): logger.warn("^Event: %s - %s" % (event['timestamp'], event['event_type'])) + # We could have warnings, but a valid event list. + if self.warnings: + instance_id = "n/a" + if len(events): + instance_id = events[0].get('instance_id') + warning_event = {'event_type': 'compute.instance.exists.warnings', + 'message_id': str(uuid.uuid4()), + 'timestamp': exists.get('timestamp', + datetime.datetime.utcnow()), + 'stream_id': int(self.stream_id), + 'instance_id': instance_id, + 'warnings': self.warnings} + events.append(warning_event) + if exists: new_event = {'event_type': event_type, 'message_id': str(uuid.uuid4()),