[codex] Add readable CCR grammar load labels

castervoice/lib/ctrl/mgr/grammar_manager.py

@@ -1,4 +1,6 @@
+import logging
 import os
+import re
 import traceback
 
 from dragonfly import Grammar
@@ -19,6 +21,9 @@
 
 
 class GrammarManager(object):
+    _ENGINE_LOGGER = logging.getLogger("engine")
+    _GRAMMAR_DISPLAY_NAMES = {}
+    _GRAMMAR_LOAD_LOG_FILTER = None
 
     def __init__(self, config,
                  merger,
@@ -70,6 +75,9 @@ def __init__(self, config,
         self._transformers_runner = t_runner
         self._companion_config = companion_config
         self._combo_validator = combo_validator
+        if GrammarManager._GRAMMAR_LOAD_LOG_FILTER is None:
+            GrammarManager._GRAMMAR_LOAD_LOG_FILTER = _GrammarLoadMessageFilter()
+            GrammarManager._ENGINE_LOGGER.addFilter(GrammarManager._GRAMMAR_LOAD_LOG_FILTER)
 
         # rules: (class name : ManagedRule}
         self._managed_rules = {}
@@ -253,11 +261,10 @@ def _remerge_ccr_rules(self, enabled_rcns):
         sorter = ConfigBasedRuleSetSorter(enabled_rcns)
         merge_result = self._merger.merge_rules(active_ccr_mrs, sorter)
         grammars = []
-        for rule_and_context in merge_result.ccr_rules_and_contexts:
-            rule = rule_and_context[0]
-            context = rule_and_context[1]
-            grammar = Grammar(name="ccr-" + GrammarManager._get_next_id(), context=context)
-            grammar.add_rule(rule)
+        for rule_load_spec in merge_result.ccr_rules_and_contexts:
+            grammar = Grammar(name="ccr-" + GrammarManager._get_next_id(), context=rule_load_spec.context)
+            GrammarManager._register_grammar_display_name(grammar.name, "Currently {}".format(rule_load_spec.display_name))
+            grammar.add_rule(rule_load_spec.rule)
             grammars.append(grammar)
         self._grammars_container.set_ccr(grammars)
         for grammar in grammars:
@@ -274,6 +281,8 @@ def _enable_non_ccr_rule(self, managed_rule, enabled):
         rcn = managed_rule.get_rule_class_name()
         if enabled:
             grammar = self._mapping_rule_maker.create_non_ccr_grammar(managed_rule)
+            GrammarManager._register_grammar_display_name(grammar.name,
+                                                          GrammarManager._build_grammar_display_name(managed_rule))
             self._grammars_container.set_non_ccr(rcn, grammar)
             grammar.load()
             return RulesEnabledDiff([rcn], frozenset())
@@ -392,3 +401,38 @@ def _get_next_id():
             GrammarManager._get_next_id.id = 0
         GrammarManager._get_next_id.id += 1
         return str(GrammarManager._get_next_id.id)
+
+    @classmethod
+    def _register_grammar_display_name(cls, grammar_name, display_name):
+        cls._GRAMMAR_DISPLAY_NAMES[grammar_name] = display_name
+
+    @classmethod
+    def _augment_engine_loading_message(cls, message):
+        match = _GrammarLoadMessageFilter.GRAMMAR_LOAD_PATTERN.search(message)
+        if match is None:
+            return message
+        grammar_name = match.group("grammar_name")
+        display_name = cls._GRAMMAR_DISPLAY_NAMES.get(grammar_name)
+        if display_name is None:
+            return message
+        return "{}{}: {}{}".format(message[:match.start("grammar_name")],
+                                   grammar_name,
+                                   display_name,
+                                   match.group("suffix"))
+
+    @staticmethod
+    def _build_grammar_display_name(managed_rule):
+        class_name = managed_rule.get_rule_class_name()
+        spoken_name = managed_rule.get_details().name
+        if spoken_name is not None and spoken_name != class_name:
+            return "{} ({})".format(class_name, spoken_name)
+        return class_name
+
+
+class _GrammarLoadMessageFilter(logging.Filter):
+    GRAMMAR_LOAD_PATTERN = re.compile(r"(?P<prefix>.*\b[Ll]oading grammar )(?P<grammar_name>\S+)(?P<suffix>\.?)$")
+
+    def filter(self, record):
+        record.msg = GrammarManager._augment_engine_loading_message(record.getMessage())
+        record.args = ()
+        return True

castervoice/lib/merge/ccrmerging2/ccrmerger2.py

@@ -6,7 +6,7 @@
 from castervoice.lib.const import CCRType
 from castervoice.lib.context import AppContext
 from castervoice.lib.ctrl.mgr.rules_enabled_diff import RulesEnabledDiff
-from castervoice.lib.merge.ccrmerging2.merge_result import MergeResult
+from castervoice.lib.merge.ccrmerging2.merge_result import MergeResult, CCRRuleLoadSpec
 
 
 class CCRMerger2(object):
@@ -56,12 +56,15 @@ def merge_rules(self, managed_rules, rule_sorter):
         compat_results = self._compatibility_checker.compatibility_check(sorted_rules)
         # 4: create one merged rule for each context, plus the no-contexts merged rule
         app_crs, non_app_crs = self._separate_app_rules(compat_results, rcns_to_details)
-        merged_rules = self._create_merged_rules(app_crs, non_app_crs)
+        merged_rule_specs = self._create_merged_rule_specs(app_crs, non_app_crs)
         # 5: turn the merged rules into repeat rules
-        repeat_rules = [self._create_repeat_rule(merged_rule) for merged_rule in merged_rules]
         contexts = CCRMerger2._create_contexts(app_crs, rcns_to_details)
-
-        rules_and_contexts = list(zip(repeat_rules, contexts))
+        rules_and_contexts = [
+            CCRRuleLoadSpec(rule=self._create_repeat_rule(rule_spec["rule"]),
+                            context=context,
+                            display_name=rule_spec["display_name"])
+            for rule_spec, context in zip(merged_rule_specs, contexts)
+        ]
         enabled_ordered_rcns = [cr.rule_class_name() for cr in compat_results]
         diff = CCRMerger2._calculate_post_merge_diff(pre_merge_rcns, enabled_ordered_rcns)
         return MergeResult(rules_and_contexts, enabled_ordered_rcns, diff)
@@ -124,17 +127,29 @@ def _separate_app_rules(self, compat_results, rcns_to_details):
                 non_app_crs.append(cr)
         return app_crs, non_app_crs
 
-    def _create_merged_rules(self, app_crs, non_app_crs):
+    def _create_merged_rule_specs(self, app_crs, non_app_crs):
         merged_rules = []
-        merged_non_app_crs_rule = self._merging_strategy.merge_into_single(non_app_crs)
+        selected_non_app_crs = self._merging_strategy.select_rules_to_merge(non_app_crs)
+        merged_non_app_crs_rule = self._merging_strategy.merge_selected_rules(selected_non_app_crs)
         if merged_non_app_crs_rule is not None:
-            merged_rules.append(merged_non_app_crs_rule)
+            merged_rules.append({
+                "rule": merged_non_app_crs_rule,
+                "display_name": self._build_display_name(selected_non_app_crs)
+            })
         for app_cr in app_crs:
             with_one_app = list(non_app_crs)
             with_one_app.append(app_cr)
-            merged_rules.append(self._merging_strategy.merge_into_single(with_one_app))
+            selected_rules = self._merging_strategy.select_rules_to_merge(with_one_app)
+            merged_rules.append({
+                "rule": self._merging_strategy.merge_selected_rules(selected_rules),
+                "display_name": self._build_display_name(selected_rules)
+            })
         return merged_rules
 
+    @staticmethod
+    def _build_display_name(compat_results):
+        return ", ".join([compat_result.rule_class_name() for compat_result in compat_results])
+
     @staticmethod
     def _create_contexts(app_crs, rcns_to_details):
         """

castervoice/lib/merge/ccrmerging2/merge_result.py

@@ -1,8 +1,15 @@
+class CCRRuleLoadSpec(object):
+    def __init__(self, rule, context, display_name):
+        self.rule = rule
+        self.context = context
+        self.display_name = display_name
+
+
 class MergeResult(object):
 
     def __init__(self, ccr_rules_and_contexts, all_rule_class_names, rules_enabled_diff):
         """
-        :param ccr_rules_and_contexts: 1-n RepeatRules and 0-n AppContexts
+        :param ccr_rules_and_contexts: 1-n CCRRuleLoadSpec instances
         :param all_rule_class_names: list of str
         :param rules_enabled_diff: RulesEnabledDiff
         """

castervoice/lib/merge/ccrmerging2/merging/base_merging_strategy.py

@@ -8,4 +8,17 @@ class BaseMergingStrategy(object):
     """
 
     def merge_into_single(self, sorted_checked_rules):
+        selected_rules = self.select_rules_to_merge(sorted_checked_rules)
+        return self.merge_selected_rules(selected_rules)
+
+    def merge_selected_rules(self, compat_results):
+        merged_rule = None
+        for compat_result in compat_results:
+            if merged_rule is None:
+                merged_rule = compat_result.rule()
+            else:
+                merged_rule = merged_rule.merge(compat_result.rule())
+        return merged_rule
+
+    def select_rules_to_merge(self, sorted_checked_rules):
         raise DontUseBaseClassError() # pylint: disable=no-value-for-parameter

castervoice/lib/merge/ccrmerging2/merging/classic_merging_strategy.py

@@ -6,13 +6,13 @@ class ClassicMergingStrategy(BaseMergingStrategy):
     This strategy KOs any incompatible rules.
     """
 
-    def merge_into_single(self, sorted_checked_rules):
+    def select_rules_to_merge(self, sorted_checked_rules):
         """
-        Merge any rules which aren't KO'd by their peers.
+        Select any rules which aren't KO'd by their peers.
         Done in O(n) for the total number of specs.
 
         :param sorted_checked_rules: list of CompatibilityResult
-        :return: MergeRule
+        :return: list of CompatibilityResult
         """
 
         length = len(sorted_checked_rules)
@@ -25,7 +25,7 @@ def merge_into_single(self, sorted_checked_rules):
             indices_map[compat_result.rule_class_name()] = index
 
         # rules with higher indices (activated "later") get priority
-        merged_rule = None
+        selected_rules = []
         for index in rule_range:
             compat_result = sorted_checked_rules[index]
             ko = False
@@ -37,8 +37,5 @@ def merge_into_single(self, sorted_checked_rules):
                     ko = True
                     break
             if not ko:
-                if merged_rule is None:
-                    merged_rule = compat_result.rule()
-                else:
-                    merged_rule = merged_rule.merge(compat_result.rule())
-        return merged_rule
+                selected_rules.append(compat_result)
+        return selected_rules

tests/lib/ctrl/mgr/test_grammarManager.py

@@ -1,3 +1,5 @@
+import logging
+
 from mock import Mock
 
 from castervoice.lib.ctrl.mgr.loading.load.initial_content import FullContentSet
@@ -45,6 +47,12 @@ def _initialize(self, content):
         self._gm.load_activation_grammars()
         self._gm.initialize()
 
+    def _engine_loading_message(self, grammar_name):
+        from castervoice.lib.ctrl.mgr.grammar_manager import GrammarManager
+        record = logging.LogRecord("engine", logging.INFO, "", 0, "Loading grammar {}".format(grammar_name), (), None)
+        GrammarManager._GRAMMAR_LOAD_LOG_FILTER.filter(record)
+        return record.msg
+
     def setUp(self):
         settings_mocking.prevent_initialize()
         settings_mocking.prevent_save()
@@ -149,6 +157,19 @@ def test_initialize_one_mergerule(self):
         self._initialize(FullContentSet([one_rule], [], []))
         self.assertEqual(2, len(self._gm._grammars_container.non_ccr.keys()))
         self.assertEqual(1, len(self._gm._grammars_container.ccr))
+        grammar_name = self._gm._grammars_container.ccr[0].name
+        self.assertEqual("Loading grammar {}: Currently Alphabet".format(grammar_name),
+                         self._engine_loading_message(grammar_name))
+
+    def test_initialize_one_non_ccr_rule_logs_readable_engine_message(self):
+        from castervoice.rules.apps.microsoft_office import outlook
+        self._setup_rules_config_file(loadable_true=["OutlookRule"], enabled=["OutlookRule"])
+        one_rule = outlook.get_rule()
+        self._initialize(FullContentSet([one_rule], [], []))
+
+        grammar_name = self._gm._grammars_container.non_ccr["OutlookRule"].name
+        self.assertEqual("Loading grammar {}: OutlookRule (outlook)".format(grammar_name),
+                         self._engine_loading_message(grammar_name))
 
     def test_initialize_two_compatible_global_mergerules(self):
         from castervoice.rules.core.alphabet_rules import alphabet

tests/lib/merge/ccrmerging2/test_CCRMerger2.py

@@ -44,7 +44,7 @@ def setUp(self):
         self.merger = Nexus._create_merger(self.selfmodrule_configurer, self.transformers_runner)
 
     def _extract_merged_rule_from_repeatrule(self, repeat_rule, index=0):
-        return repeat_rule[index][0]._extras["caster_base_sequence"]._child._children[0]._rule
+        return repeat_rule[index].rule._extras["caster_base_sequence"]._child._children[0]._rule
 
     def test_merge_empty(self):
         """
@@ -60,10 +60,11 @@ def test_merge_nonempty(self):
         result = self.merger.merge_rules([navigation_mr], self.sorter)
 
         self.assertEqual(1, len(result.ccr_rules_and_contexts))
-        repeat_rule = result.ccr_rules_and_contexts[0][0]
-        context = result.ccr_rules_and_contexts[0][1]
+        repeat_rule = result.ccr_rules_and_contexts[0].rule
+        context = result.ccr_rules_and_contexts[0].context
         self.assertEqual("RepeatRule", repeat_rule.__class__.__name__)
         self.assertIsInstance(context, FuncContext)
+        self.assertEqual("Navigation", result.ccr_rules_and_contexts[0].display_name)
 
     def test_merge_two(self):
         """
@@ -74,8 +75,8 @@ def test_merge_two(self):
         result = self.merger.merge_rules([alphabet_mr, navigation_mr], self.sorter)
 
         self.assertEqual(1, len(result.ccr_rules_and_contexts))
-        repeat_rule = result.ccr_rules_and_contexts[0][0]
-        context = result.ccr_rules_and_contexts[0][1]
+        repeat_rule = result.ccr_rules_and_contexts[0].rule
+        context = result.ccr_rules_and_contexts[0].context
         self.assertEqual("RepeatRule", repeat_rule.__class__.__name__)
         self.assertIsInstance(context, FuncContext)
 
@@ -93,6 +94,7 @@ def test_merge_two_incompatible(self):
         rule = self._extract_merged_rule_from_repeatrule(result.ccr_rules_and_contexts)
         self.assertIn("two exclusive", rule._mapping)
         self.assertNotIn("one exclusive", rule._mapping)
+        self.assertEqual("FakeRuleTwo", result.ccr_rules_and_contexts[0].display_name)
 
     def test_merge_one_context_one_no_context(self):
         """
@@ -105,10 +107,10 @@ def test_merge_one_context_one_no_context(self):
         result = self.merger.merge_rules([eclipse_mr, navigation_mr], self.sorter)
 
         self.assertEqual(2, len(result.ccr_rules_and_contexts))
-        self.assertEqual("RepeatRule", result.ccr_rules_and_contexts[0][0].__class__.__name__)
-        self.assertEqual("RepeatRule", result.ccr_rules_and_contexts[1][0].__class__.__name__)
-        self.assertIsInstance(result.ccr_rules_and_contexts[0][1], FuncContext)
-        self.assertIsInstance(result.ccr_rules_and_contexts[1][1], Context)
+        self.assertEqual("RepeatRule", result.ccr_rules_and_contexts[0].rule.__class__.__name__)
+        self.assertEqual("RepeatRule", result.ccr_rules_and_contexts[1].rule.__class__.__name__)
+        self.assertIsInstance(result.ccr_rules_and_contexts[0].context, FuncContext)
+        self.assertIsInstance(result.ccr_rules_and_contexts[1].context, Context)
 
     def test_words_txt_transformer(self):
         """
@@ -142,15 +144,21 @@ def test_merge_two_app_ccr(self):
         result = self.merger.merge_rules([alphabet_mr, eclipse_app_mr, vscode_app_mr], self.sorter)
 
         self.assertEqual(3, len(result.ccr_rules_and_contexts))
-        repeat_rule_1, context_1 = result.ccr_rules_and_contexts[0]
-        repeat_rule_2, context_2 = result.ccr_rules_and_contexts[1]
-        repeat_rule_3, context_3 = result.ccr_rules_and_contexts[2]
+        repeat_rule_1 = result.ccr_rules_and_contexts[0].rule
+        context_1 = result.ccr_rules_and_contexts[0].context
+        repeat_rule_2 = result.ccr_rules_and_contexts[1].rule
+        context_2 = result.ccr_rules_and_contexts[1].context
+        repeat_rule_3 = result.ccr_rules_and_contexts[2].rule
+        context_3 = result.ccr_rules_and_contexts[2].context
         self.assertEqual("RepeatRule", repeat_rule_1.__class__.__name__)
         self.assertEqual("RepeatRule", repeat_rule_2.__class__.__name__)
         self.assertEqual("RepeatRule", repeat_rule_3.__class__.__name__)
         self.assertIsInstance(context_1, FuncContext)
         self.assertIsInstance(context_2, AppContext)
         self.assertIsInstance(context_3, AppContext)
+        self.assertEqual("Alphabet", result.ccr_rules_and_contexts[0].display_name)
+        self.assertEqual("Alphabet, EclipseCCR", result.ccr_rules_and_contexts[1].display_name)
+        self.assertEqual("Alphabet, VSCodeCcrRule", result.ccr_rules_and_contexts[2].display_name)
 
         self._evaluate_context_in_every_permutation([context_1, context_2, context_3],
             [True,False,False],
@@ -183,7 +191,7 @@ def fear_of_the_bug():
         vscode_app_mr = TestCCRMerger2._create_managed_rule(VSCodeCcrRule, CCRType.APP, "vscode",function = nice_function)
         result = self.merger.merge_rules([alphabet_mr, eclipse_app_mr, vscode_app_mr], self.sorter)
 
-        contexts = [x[1] for x in result.ccr_rules_and_contexts]
+        contexts = [load_spec.context for load_spec in result.ccr_rules_and_contexts]
         self.assertEqual(3, len(result.ccr_rules_and_contexts))       
 
         # check that we get the same result no matter what the order
@@ -235,7 +243,7 @@ def second_context():
         vscode_app_mr = TestCCRMerger2._create_managed_rule(VSCodeCcrRule, CCRType.APP,"vscode",function = second_context)
         result = self.merger.merge_rules([alphabet_mr, eclipse_app_mr, vscode_app_mr], self.sorter)
 
-        contexts = [x[1] for x in result.ccr_rules_and_contexts]
+        contexts = [load_spec.context for load_spec in result.ccr_rules_and_contexts]
         self.assertEqual(3, len(result.ccr_rules_and_contexts))       
         for c in permutations(contexts):
             self._evaluate_contexts(c,dict(executable= "vscode", title = "hello",handle=None))