refactor measure_time

logprep/abc/processor.py

@@ -157,24 +157,34 @@ def process(self, event: dict):
         self._process_rule_tree(event, self._specific_tree)
         self._process_rule_tree(event, self._generic_tree)
 
-    @Metric.measure_time()
     def _process_rule_tree(self, event: dict, tree: "RuleTree"):
         applied_rules = set()
 
         @Metric.measure_time()
-        def _process_rule(event, rule):
+        def _process_rule(rule, event):
             self._apply_rules_wrapper(event, rule)
             rule.metrics.number_of_processed_events += 1
             applied_rules.add(rule)
             return event
 
-        if self._config.apply_multiple_times:
+        @Metric.measure_time()
+        def _process_rule_tree_multiple_times(tree, event):
             matching_rules = tree.get_matching_rules(event)
             while matching_rules:
-                reduce(_process_rule, (event, *matching_rules))
+                for rule in matching_rules:
+                    _process_rule(rule, event)
                 matching_rules = set(tree.get_matching_rules(event)).difference(applied_rules)
+
+        @Metric.measure_time()
+        def _process_rule_tree_once(tree, event):
+            matching_rules = tree.get_matching_rules(event)
+            for rule in matching_rules:
+                _process_rule(rule, event)
+
+        if self._config.apply_multiple_times:
+            _process_rule_tree_multiple_times(tree, event)
         else:
-            reduce(_process_rule, (event, *tree.get_matching_rules(event)))
+            _process_rule_tree_once(tree, event)
 
     def _apply_rules_wrapper(self, event: dict, rule: "Rule"):
         try:

logprep/metrics/metrics.py

@@ -87,16 +87,10 @@ def measure_time(metric_name: str = "processing_time_per_event"):
         """Decorate function to measure execution time for function and add results to event."""
 
         def inner_decorator(func):
-            def inner(*args, **kwargs):  # nosemgrep
-                begin = time.time()
-                result = func(*args, **kwargs)
-                end = time.time()
-                processing_time = end - begin
-                caller = args[0]
-                if func.__name__ in ("_process_rule_tree", "_process_rule"):
-                    caller = args[-1]
-                metric = getattr(caller.metrics, metric_name)
-                metric += processing_time
+            def inner(self, *args, **kwargs):  # nosemgrep
+                metric = getattr(self.metrics, metric_name)
+                with metric.tracker.labels(**metric.labels).time():
+                    result = func(self, *args, **kwargs)
                 return result
 
             return inner

tests/unit/metrics/test_metrics.py

@@ -238,25 +238,29 @@ class TestComponentMetric:
     class Metrics(Component.Metrics):
         """test class"""
 
+        custom_registry = CollectorRegistry()
+
         test_metric_number_1: CounterMetric = CounterMetric(
             name="test_metric_number_1",
             description="empty description",
+            registry=custom_registry,
         )
 
         test_metric_without_label_values: CounterMetric = CounterMetric(
             name="test_metric_number_1",
             description="empty description",
             inject_label_values=False,
+            registry=custom_registry,
         )
 
-    def setup_method(self):
-        self.custom_registry = CollectorRegistry()
-        TestComponentMetric.Metrics.test_metric_histogram = HistogramMetric(
+        test_metric_histogram: HistogramMetric = HistogramMetric(
             name="test_metric_histogram",
             description="empty description",
             labels={"pipeline": "1"},
-            registry=self.custom_registry,
+            registry=custom_registry,
         )
+
+    def setup_method(self):
         self.metrics = self.Metrics(labels={"label1": "value1", "label2": "value2"})
 
     def test_init(self):
@@ -298,7 +302,7 @@ def decorated_function(self):
         pass
 
     def test_measure_time_measures(self):
-        metric_output = generate_latest(self.custom_registry).decode("utf-8")
+        metric_output = generate_latest(self.metrics.custom_registry).decode("utf-8")
         assert re.search(r'test_metric_histogram_sum\{pipeline="1"\} 0\.0', metric_output)
         assert re.search(r'test_metric_histogram_count\{pipeline="1"\} 0\.0', metric_output)
         assert re.search(
@@ -307,7 +311,7 @@ def test_measure_time_measures(self):
 
         self.decorated_function()
 
-        metric_output = generate_latest(self.custom_registry).decode("utf-8")
+        metric_output = generate_latest(self.metrics.custom_registry).decode("utf-8")
         assert not re.search(r'test_metric_histogram_sum\{pipeline="1"\} 0\.0', metric_output)
         assert re.search(r'test_metric_histogram_count\{pipeline="1"\} 1\.0', metric_output)
         assert re.search(