chore(issues): Cleanup apply_rule logs and add some more for regressions (#54455)

Add more logs for regression evaluation, but limit them to a specific
project

src/sentry/conf/server.py

@@ -1696,6 +1696,8 @@ SENTRY_FEATURES = {
     "organizations:sdk-crash-detection": False,
     # Enable functionality for recap server polling.
     "organizations:recap-server": False,
+    # Enable additional logging for alerts
+    "organizations:detailed-alert-logging": False,
     # Adds additional filters and a new section to issue alert rules.
     "projects:alert-filters": True,
     # Enable functionality to specify custom inbound filters on events.

src/sentry/event_manager.py

@@ -1821,18 +1821,44 @@ def _create_group(project: Project, event: Event, **kwargs: Any) -> Group:
 
 
 def _handle_regression(group: Group, event: Event, release: Optional[Release]) -> Optional[bool]:
+    should_log_extra_info = features.has(
+        "organizations:detailed-alert-logging", group.project.organization
+    )
+    logging_details = {
+        "group_id": group.id,
+        "event_id": event.event_id,
+    }
+    if should_log_extra_info:
+        logger.info("_handle_regression", extra={**logging_details})
+
     if not group.is_resolved():
+        if should_log_extra_info:
+            logger.info(
+                "_handle_regression: group.is_resolved returned true", extra={**logging_details}
+            )
         return None
 
     # we only mark it as a regression if the event's release is newer than
     # the release which we originally marked this as resolved
     elif GroupResolution.has_resolution(group, release):
+        if should_log_extra_info:
+            logger.info(
+                "_handle_regression: group.is_resolved returned true", extra={**logging_details}
+            )
         return None
 
     elif has_pending_commit_resolution(group):
+        if should_log_extra_info:
+            logger.info(
+                "_handle_regression: group.is_resolved returned true", extra={**logging_details}
+            )
         return None
 
     if not plugin_is_regression(group, event):
+        if should_log_extra_info:
+            logger.info(
+                "_handle_regression: group.is_resolved returned true", extra={**logging_details}
+            )
         return None
 
     # we now think its a regression, rely on the database to validate that
@@ -1859,6 +1885,12 @@ def _handle_regression(group: Group, event: Event, release: Optional[Release]) -
             substatus=GroupSubStatus.REGRESSED,
         )
     )
+    if should_log_extra_info:
+        logger.info(
+            f"_handle_regression: is_regression evaluated to {is_regression}",
+            extra={**logging_details},
+        )
+
     group.active_at = date
     group.status = GroupStatus.UNRESOLVED
     group.substatus = GroupSubStatus.REGRESSED

src/sentry/features/__init__.py

@@ -267,6 +267,7 @@ default_manager.add("organizations:ds-org-recalibration", OrganizationFeature, F
 default_manager.add("organizations:slack-disable-on-broken", OrganizationFeature, FeatureHandlerStrategy.REMOTE)
 default_manager.add("organizations:sourcemaps-bundle-flat-file-indexing", OrganizationFeature, FeatureHandlerStrategy.REMOTE)
 default_manager.add("organizations:recap-server", OrganizationFeature, FeatureHandlerStrategy.INTERNAL)
+default_manager.add("organizations:detailed-alert-logging", OrganizationFeature, FeatureHandlerStrategy.INTERNAL)
 
 # Project scoped features
 default_manager.add("projects:alert-filters", ProjectFeature, FeatureHandlerStrategy.INTERNAL)

src/sentry/rules/processor.py

@@ -8,7 +8,7 @@ from typing import Any, Callable, Collection, List, Mapping, MutableMapping, Seq
 from django.core.cache import cache
 from django.utils import timezone
 
-from sentry import analytics
+from sentry import analytics, features
 from sentry.eventstore.models import GroupEvent
 from sentry.models import Environment, GroupRuleStatus, Rule
 from sentry.models.rulesnooze import RuleSnooze
@@ -166,10 +166,9 @@ class RuleProcessor:
         :param rule: `Rule` object
         :return: void
         """
-        condition_match = rule.data.get("action_match") or Rule.DEFAULT_CONDITION_MATCH
-        filter_match = rule.data.get("filter_match") or Rule.DEFAULT_FILTER_MATCH
-        rule_condition_list = rule.data.get("conditions", ())
-        frequency = rule.data.get("frequency") or Rule.DEFAULT_FREQUENCY
+        should_log_extra_info = features.has(
+            "organizations:detailed-alert-logging", self.project.organization
+        )
         logging_details = {
             "rule_id": rule.id,
             "group_id": self.group.id,
@@ -180,46 +179,50 @@ class RuleProcessor:
             "has_reappeared": self.has_reappeared,
             "new_group_environment": self.is_new_group_environment,
         }
-
-        self.logger.info(
-            "apply_rule",
-            extra={**logging_details},
-        )
-        try:
-            environment = self.event.get_environment()
+        if should_log_extra_info:
             self.logger.info(
-                "apply_rule got environment",
+                "apply_rule",
                 extra={**logging_details},
             )
+
+        condition_match = rule.data.get("action_match") or Rule.DEFAULT_CONDITION_MATCH
+        filter_match = rule.data.get("filter_match") or Rule.DEFAULT_FILTER_MATCH
+        rule_condition_list = rule.data.get("conditions", ())
+        frequency = rule.data.get("frequency") or Rule.DEFAULT_FREQUENCY
+        try:
+            environment = self.event.get_environment()
         except Environment.DoesNotExist:
-            self.logger.info(
-                "apply_rule environment does not exist",
-                extra={**logging_details},
-            )
+            if should_log_extra_info:
+                self.logger.info(
+                    "apply_rule environment does not exist",
+                    extra={**logging_details},
+                )
             return
 
         if rule.environment_id is not None and environment.id != rule.environment_id:
-            self.logger.info(
-                "apply_rule environment does not match",
-                extra={
-                    **logging_details,
-                    "rule_environment_id": rule.environment_id,
-                    "event_environment_id": environment.id,
-                },
-            )
+            if should_log_extra_info:
+                self.logger.info(
+                    "apply_rule environment does not match",
+                    extra={
+                        **logging_details,
+                        "rule_environment_id": rule.environment_id,
+                        "event_environment_id": environment.id,
+                    },
+                )
             return
 
         now = timezone.now()
         freq_offset = now - timedelta(minutes=frequency)
         if status.last_active and status.last_active > freq_offset:
-            self.logger.info(
-                "apply_rule skipping rule because of last_active",
-                extra={
-                    **logging_details,
-                    "last_active": status.last_active,
-                    "freq_offset": freq_offset,
-                },
-            )
+            if should_log_extra_info:
+                self.logger.info(
+                    "apply_rule skipping rule because of last_active",
+                    extra={
+                        **logging_details,
+                        "last_active": status.last_active,
+                        "freq_offset": freq_offset,
+                    },
+                )
             return
 
         state = self.get_state()
@@ -232,7 +235,7 @@ class RuleProcessor:
                 if (
                     rule_cond.get("id", None)
                     == "sentry.rules.conditions.regression_event.RegressionEventCondition"
-                ):
+                ) and should_log_extra_info:
                     self.logger.info("apply_rule got regression_event", extra={**logging_details})
             else:
                 filter_list.append(rule_cond)
@@ -250,10 +253,11 @@ class RuleProcessor:
             predicate_func = get_match_function(match)
             if predicate_func:
                 if not predicate_func(predicate_iter):
-                    self.logger.info(
-                        "apply_rule invalid predicate_func",
-                        extra={**logging_details},
-                    )
+                    if should_log_extra_info:
+                        self.logger.info(
+                            "apply_rule invalid predicate_func",
+                            extra={**logging_details},
+                        )
                     return
             else:
                 self.logger.error(
@@ -271,10 +275,11 @@ class RuleProcessor:
         )
 
         if not updated:
-            self.logger.info(
-                "apply_rule not updated",
-                extra={**logging_details},
-            )
+            if should_log_extra_info:
+                self.logger.info(
+                    "apply_rule not updated",
+                    extra={**logging_details},
+                )
             return
 
         if randrange(10) == 0: