Group all event searches

To avoid searching the same file more than once we now
gather all searches from all events and executed all
searches for a given file once.

Related-to: canonical#850

hotsos/client.py

@@ -213,10 +213,7 @@ def __init__(self, plugins=None):
         all will be run.
         """
         self._summary = OutputManager()
-        if plugins:
-            self.plugins = plugins
-        else:
-            self.plugins = plugintools.PLUGINS.keys()
+        self.plugins = plugins or plugintools.PLUGINS.keys()
 
     def setup_global_env(self):
         """ State saved here persists across all plugin runs. """

hotsos/core/plugintools.py

@@ -7,6 +7,7 @@
 from hotsos.core.issues import IssuesManager
 from hotsos.core.log import log
 from hotsos.core.ycheck.scenarios import YScenarioChecker
+from hotsos.core.ycheck.events import EventDefsPreloader
 
 PLUGINS = {}
 PLUGIN_RUN_ORDER = []
@@ -393,6 +394,7 @@ def run(self):
         failed_parts = []
         # The following are executed as part of each plugin run (but not last).
         ALWAYS_RUN = {'auto_scenario_check': YScenarioChecker}
+        ALWAYS_RUN['events_preload'] = EventDefsPreloader
         for name, always_parts in ALWAYS_RUN.items():
             # update current env to reflect actual part being run
             HotSOSConfig.part_name = name

hotsos/core/ycheck/events.py

@@ -1,5 +1,6 @@
 import abc
 from functools import cached_property
+from collections import UserDict
 
 from hotsos.core.config import HotSOSConfig
 from hotsos.core.log import log
@@ -13,6 +14,7 @@
     YHandlerBase,
     YDefsSection,
 )
+from hotsos.core.ycheck.engine.properties import search
 from hotsos.core.ycheck.engine.properties.search import CommonTimestampMatcher
 
 
@@ -225,7 +227,149 @@ def __call__(self):
         """ Callback method. """
 
 
-class EventHandlerBase(YHandlerBase, EventProcessingUtils):
+class EventRegistryError(Exception):
+    def __init__(self, key, all_keys):
+        self.key = key
+        self.all_keys = all_keys
+
+    def __str__(self):
+        return ("Key '{}' not found in event registry. Available keys are:"
+                "\n      - {}".
+                format(self.key, '\n      - '.join(self.all_keys)))
+
+
+class EventsRegistry(UserDict):
+
+    def __getitem__(self, key):
+        try:
+            return super().__getitem__(key)
+        except KeyError:
+            raise EventRegistryError(key, list(self.data)) from KeyError
+
+    def reset(self):
+        self.data = {}
+
+
+class EventsBase(object):
+    _global_searcher = None
+    _events_registry = EventsRegistry()
+
+    @property
+    def registry(self):
+        return self._events_registry
+
+    def get_global_searcher(self, reset=False):
+        cls = EventsBase
+        if not reset and cls._global_searcher:
+            log.error("USING GLOBAL SEARCHER %s", cls._global_searcher)
+            return cls._global_searcher
+
+        constraint = SearchConstraintSearchSince(
+                                         ts_matcher_cls=CommonTimestampMatcher)
+        searcher = FileSearcher(constraint=constraint)
+        cls._global_searcher = searcher
+        log.error("CREATING GLOBAL SEARCHER %s", cls._global_searcher)
+        return searcher
+
+    def meets_requirements(self, event):
+        if HotSOSConfig.force_mode:
+            return True
+
+        if event.requires and not event.requires.result:
+            log.error("event '%s' pre-requisites not met - "
+                      "skipping", event.name)
+            return False
+
+        return True
+
+    def skip_filtered_event(self, event_path):
+        if not HotSOSConfig.event_filter:
+            return False
+
+        if event_path == HotSOSConfig.event_filter:
+            return False
+
+        log.info("skipping event %s (filter=%s)", event_path,
+                 HotSOSConfig.event_filter)
+        return True
+
+    def get_defs(self, group=None):
+        plugin_defs = YDefsLoader('events').plugin_defs
+        if not plugin_defs:
+            return {}
+
+        log.error("loading event defs (group=%s)", group)
+        group_defs = plugin_defs
+        if not group:
+            return group_defs
+
+        group_defs = {group: group_defs[group]}
+
+        # ensure we only include the events we want
+        for entry in group.split('.'):
+            group_defs[entry] = group_defs[entry]
+
+        log.error("loaded %s", group_defs)
+        return group_defs
+
+    def load_searches(self):
+        self.registry.reset()
+        global_searcher = self.get_global_searcher(reset=True)
+        search_props = set()
+        events = YDefsSection(HotSOSConfig.plugin_name, self.get_defs() or {})
+        for prop in events.manager.properties.values():
+            for item in prop:
+                if not issubclass(item['cls'], search.YPropertySearch):
+                    break
+
+                search_props.add(item['path'])
+
+        for proppath in search_props:
+            if self.skip_filtered_event(proppath):
+                continue
+
+            s = None
+            proppath = proppath.partition('.')[2]
+            event = None
+            for prop in proppath.split('.'):
+                if s is None:
+                    s = getattr(events, prop)
+                else:
+                    s = getattr(s, prop)
+
+                if not s:
+                    continue
+
+                if not isinstance(s, search.YPropertySearch):
+                    event = s
+                else:
+                    break
+
+            if event.input.command:
+                # don't apply constraints to command outputs
+                allow_constraints = False
+            else:
+                allow_constraints = True
+
+            for path in event.input.paths:
+                log.debug("loading search for event %s path %s (tag=%s)",
+                          proppath,
+                          path, event.search.unique_search_tag)
+                # remove the .search
+                rkey = proppath.rpartition('.')[0]
+                # these may be needed later e.g. for sequence lookups
+                self.registry[rkey] = {'search': event.search}
+                event.search.load_searcher(global_searcher, path,
+                                           allow_constraints=allow_constraints)
+
+
+class EventDefsPreloader(EventsBase):
+
+    def load_and_run(self):
+        self.load_searches()
+
+
+class EventHandlerBase(EventsBase, YHandlerBase, EventProcessingUtils):
     """
     Root name used to identify a group of event definitions. Once all the
     yaml definitions are loaded this defines the level below which events
@@ -241,10 +385,9 @@ def __init__(self, *args, searcher=None, **kwargs):
                          done at once.
         """
         super().__init__(*args, **kwargs)
-        if not searcher:
-            log.debug("creating searcher for event checker")
-            searcher = FileSearcher(constraint=SearchConstraintSearchSince(
-                                        ts_matcher_cls=CommonTimestampMatcher))
+        if searcher is None:
+            log.debug("using global searcher for event checker")
+            searcher = self.get_global_searcher()
 
         self._searcher = searcher
         self._event_results = None
@@ -254,72 +397,37 @@ def searcher(self):
         return self._searcher
 
     @cached_property
-    def event_definitions(self):
+    def events(self):
         """ Load event definitions from yaml. """
-        _event_defs = {}
-
-        plugin = YDefsLoader('events').plugin_defs
-        if not plugin:
-            return _event_defs
-
-        log.debug("loading defs for subgroup=%s", self.event_group)
-        ytree = plugin
-        ypath = self.event_group.split('.')
-        for i, g in enumerate(ypath):
-            if i >= len(ypath) - 1:
-                group_defs = ytree.get(g)
-            else:
-                ytree = ytree.get(g)
-
-        group = YDefsSection(self.event_group, group_defs)
+        group = YDefsSection(HotSOSConfig.plugin_name,
+                             self.get_defs(self.event_group) or {})
         log.debug("sections=%s, events=%s",
                   len(list(group.branch_sections)),
                   len(list(group.leaf_sections)))
 
+        _events = {}
         for event in group.leaf_sections:
-            fullname = "{}.{}.{}".format(HotSOSConfig.plugin_name,
-                                         event.parent.name, event.name)
-            if (HotSOSConfig.event_filter and
-                    fullname != HotSOSConfig.event_filter):
-                log.info("skipping event %s (filter=%s)", fullname,
-                         HotSOSConfig.event_filter)
+            if self.skip_filtered_event(event.resolve_path):
                 continue
 
-            if (not HotSOSConfig.force_mode and event.requires and not
-                    event.requires.result):
-                log.error("event '%s' pre-requisites not met - "
-                          "skipping", event.name)
+            if not self.meets_requirements(event):
                 return {}
 
             log.debug("event: %s", event.name)
             log.debug("input: %s (command=%s)", event.input.paths,
                       event.input.command is not None)
 
             section_name = event.parent.name
-            if section_name not in _event_defs:
-                _event_defs[section_name] = {}
-
-            for path in event.input.paths:
-                if event.input.command:
-                    # don't apply constraints to command outputs
-                    allow_constraints = False
-                else:
-                    allow_constraints = True
-
-                event.search.load_searcher(self.searcher, path,
-                                           allow_constraints=allow_constraints)
+            if section_name not in _events:
+                _events[section_name] = {}
 
-            passthrough = bool(event.search.passthrough_results)
-            emeta = {'passthrough': passthrough,
-                     'sequence': event.search.sequence_search,
-                     'tag': event.search.unique_search_tag}
-            _event_defs[section_name][event.name] = emeta
+            _events[section_name][event.name] = \
+                                           event.resolve_path.partition('.')[2]
 
-        return _event_defs
+        return _events
 
     def load(self):
-        """ Pre-load event definitions. """
-        self.event_definitions
+        pass
 
     @property
     def final_event_results(self):
@@ -340,18 +448,20 @@ def run(self, results):
             raise Exception("need to register at least one callback for "
                             "event handler.")
 
-        log.debug("registered callbacks:\n%s", '\n'.join(CALLBACKS.keys()))
+        log.debug("registered event callbacks:\n%s", '\n'.
+                  join(CALLBACKS.keys()))
         info = {}
-        for section_name, section in self.event_definitions.items():
-            for event, event_meta in section.items():
-                search_tag = event_meta['tag']
+        for section_name, section in self.events.items():
+            for event, fullname in section.items():
+                event_search = self.registry[fullname]['search']
+                search_tag = event_search.unique_search_tag
                 seq_def = None
-                if event_meta['passthrough']:
+                if bool(event_search.passthrough_results):
                     # this is for implementations that have their own means of
                     # retrieving results.
                     search_results = results
                 else:
-                    seq_def = event_meta['sequence']
+                    seq_def = event_search.sequence_search
                     if seq_def:
                         search_results = results.find_sequence_sections(
                             seq_def)
@@ -361,7 +471,8 @@ def run(self, results):
                         search_results = results.find_by_tag(search_tag)
 
                 if not search_results:
-                    log.debug("event %s did not yield any results", event)
+                    log.debug("event %s did not yield any results (tag=%s)",
+                              event, search_tag)
                     continue
 
                 # We want this to throw an exception if the callback is not

tests/unit/storage/test_ceph_mon.py

@@ -6,6 +6,7 @@
 from hotsos.core.plugins.storage import (
     ceph as ceph_core,
 )
+from hotsos.core.ycheck.events import EventDefsPreloader
 from hotsos.plugin_extensions.storage import ceph_summary, ceph_event_checks
 
 from .. import utils
@@ -401,6 +402,9 @@ def test_ceph_daemon_log_checker(self, mock_cli):
         mock_cli.return_value = mock.MagicMock()
         # ensure log file contents are within allowed timeframe ("since")
         mock_cli.return_value.date.return_value = "2022-02-10 00:00:00"
+        # NOTE: this has to be done AFTER the data root is set hence why we do
+        # it here.
+        EventDefsPreloader().load_searches()
         result = {'osd-reported-failed': {'osd.41': {'2022-02-08': 23},
                                           'osd.85': {'2022-02-08': 4}},
                   'long-heartbeat-pings': {'2022-02-09': 4},

tests/unit/storage/test_ceph_osd.py

@@ -5,6 +5,7 @@
 from hotsos.core.plugins.storage import (
     ceph as ceph_core,
 )
+from hotsos.core.ycheck.events import EventDefsPreloader
 from hotsos.plugin_extensions.storage import (
     ceph_summary,
     ceph_event_checks,
@@ -210,6 +211,9 @@ def test_ceph_daemon_log_checker(self, mock_cli):
         mock_cli.return_value = mock.MagicMock()
         # ensure log file contents are within allowed timeframe ("since")
         mock_cli.return_value.date.return_value = "2021-01-01 00:00:00"
+        # NOTE: this has to be done AFTER the data root is set hence why we do
+        # it here.
+        EventDefsPreloader().load_searches()
         result = {'crc-err-bluestore': {'2021-02-12': 5, '2021-02-13': 1},
                   'crc-err-rocksdb': {'2021-02-12': 7}}
         inst = ceph_event_checks.CephEventHandler()