updated telemetry event dependency to opentelemetry LoggingHandler

Author: yuanqu72

featuremanagement/azuremonitor/_send_telemetry.py

@@ -12,20 +12,38 @@
 
 logger = logging.getLogger(__name__)
 
+# Set up a separate logger for feature-evaluation telemetry events to avoid propagating to the root logger
+_event_logger = logging.getLogger(__name__ + ".events")
+_event_logger.propagate = False
+
 try:
-    from azure.monitor.events.extension import track_event as azure_monitor_track_event  # type: ignore
-    from opentelemetry.context.context import Context
-    from opentelemetry.sdk.trace import Span, SpanProcessor
+    from logging import INFO
+    from opentelemetry.instrumentation.logging.handler import LoggingHandler
+    from opentelemetry.sdk.trace import SpanProcessor
 
-    HAS_AZURE_MONITOR_EVENTS_EXTENSION = True
+    HAS_OPENTELEMETRY_LOGGING = True
 except ImportError:
-    HAS_AZURE_MONITOR_EVENTS_EXTENSION = False
-    logger.warning(
-        "azure-monitor-events-extension is not installed. Telemetry will not be sent to Application Insights."
-    )
+    HAS_OPENTELEMETRY_LOGGING = False
+    LoggingHandler = object  # type: ignore
     SpanProcessor = object  # type: ignore
-    Span = object  # type: ignore
-    Context = object  # type: ignore
+
+
+_events_logger_initialized = False
+
+def _initialize_event_logger() -> None:
+    global _events_logger_initialized
+    if _events_logger_initialized:
+        return
+
+    if not HAS_OPENTELEMETRY_LOGGING:
+        logger.warning(
+            "OpenTelemetry logging handler is not installed. Telemetry will not be sent to Application Insights."
+        )
+        return
+
+    _event_logger.addHandler(LoggingHandler())
+    _event_logger.setLevel(INFO)
+    _events_logger_initialized = True
 
 FEATURE_NAME = "FeatureName"
 ENABLED = "Enabled"
@@ -51,15 +69,22 @@ def track_event(event_name: str, user: str, event_properties: Optional[Dict[str,
     :param str user: The user ID to associate with the event.
     :param dict[str, str] event_properties: A dictionary of named string properties.
     """
-    if not HAS_AZURE_MONITOR_EVENTS_EXTENSION:
+    if not HAS_OPENTELEMETRY_LOGGING:
         return
 
+    _initialize_event_logger()
+
     event_properties = event_properties or {}
 
     if user:
         event_properties[TARGETING_ID] = user
 
-    azure_monitor_track_event(event_name, event_properties)
+    # Azure Monitor exporter maps this attribute to customEvent telemetry name.
+    custom_event_attributes = {
+        **event_properties,
+        "microsoft.custom_event.name": event_name,
+    }
+    _event_logger.info(event_name, extra=custom_event_attributes)
 
 
 def publish_telemetry(evaluation_event: EvaluationEvent) -> None:
@@ -68,7 +93,7 @@ def publish_telemetry(evaluation_event: EvaluationEvent) -> None:
 
     :param EvaluationEvent evaluation_event: The evaluation event to publish telemetry for.
     """
-    if not HAS_AZURE_MONITOR_EVENTS_EXTENSION:
+    if not HAS_OPENTELEMETRY_LOGGING:
         return
 
     feature = evaluation_event.feature
@@ -129,15 +154,15 @@ def __init__(self, **kwargs: Any) -> None:
             "targeting_context_accessor", None
         )
 
-    def on_start(self, span: Span, parent_context: Optional[Context] = None) -> None:  # pylint: disable=unused-argument
+    def on_start(self, span: Any, parent_context: Optional[Any] = None) -> None:  # pylint: disable=unused-argument
         """
         Attaches the targeting ID to the span and baggage when a new span is started.
 
         :param Span span: The span that was started.
         :param parent_context: The parent context of the span.
         """
-        if not HAS_AZURE_MONITOR_EVENTS_EXTENSION:
-            logger.warning("Azure Monitor Events Extension is not installed.")
+        if not HAS_OPENTELEMETRY_LOGGING:
+            logger.warning("OpenTelemetry logging handler is not installed.")
             return
         if self._targeting_context_accessor and callable(self._targeting_context_accessor):
             if inspect.iscoroutinefunction(self._targeting_context_accessor):

pyproject.toml

@@ -58,10 +58,9 @@ Homepage = "https://github.com/microsoft/FeatureManagement-Python"
 Issues = "https://github.com/microsoft/FeatureManagement-Python/issues"
 
 [project.optional-dependencies]
-AzureMonitor = ["azure-monitor-events-extension<2.0.0"]
+AzureMonitor = ["azure-monitor-opentelemetry < 2.0.0"]
 test = [
     "azure-monitor-opentelemetry < 2.0.0",
-    "azure-monitor-events-extension < 2.0.0",
 ]
 dev = [
     "pytest >= 7.0.0, < 10.0.0",
@@ -76,4 +75,5 @@ dev = [
     "myst_parser >= 2.0.0, < 6.0.0",
     "opentelemetry-api >= 1.20.0, < 2.0.0",
     "opentelemetry-sdk >= 1.20.0, < 2.0.0",
+    "opentelemetry-instrumentation-logging >= 0.40b0, < 1.0.0",
 ]

tests/test_send_telemetry_appinsights.py

@@ -13,6 +13,10 @@
 from featuremanagement.azuremonitor import TargetingSpanProcessor
 
 
+def _event_properties(mock_track_event):
+    return mock_track_event.call_args.kwargs["event_properties"]
+
+
 @pytest.mark.usefixtures("caplog")
 class TestSendTelemetryAppinsights:
 
@@ -40,23 +44,45 @@ def test_send_telemetry_appinsights(self):
         evaluation_event.variant = variant
         evaluation_event.reason = VariantAssignmentReason.DEFAULT_WHEN_DISABLED
 
-        with patch("featuremanagement.azuremonitor._send_telemetry.azure_monitor_track_event") as mock_track_event:
+        with patch("featuremanagement.azuremonitor._send_telemetry.track_event") as mock_track_event:
             # This is called like this so we can override the track_event function
             featuremanagement.azuremonitor._send_telemetry.publish_telemetry(  # pylint: disable=protected-access
                 evaluation_event
             )
             mock_track_event.assert_called_once()
             assert mock_track_event.call_args[0][0] == "FeatureEvaluation"
-            assert mock_track_event.call_args[0][1]["FeatureName"] == "TestFeature"
-            assert mock_track_event.call_args[0][1]["Enabled"] == "True"
-            assert mock_track_event.call_args[0][1]["TargetingId"] == "test_user"
-            assert mock_track_event.call_args[0][1]["Variant"] == "TestVariant"
-            assert mock_track_event.call_args[0][1]["ETag"] == "cmwBRcIAq1jUyKL3Kj8bvf9jtxBrFg-R-ayExStMC90"
+            assert mock_track_event.call_args[0][1] == "test_user"
+            event_properties = _event_properties(mock_track_event)
+            assert event_properties["FeatureName"] == "TestFeature"
+            assert event_properties["Enabled"] == "True"
+            assert event_properties["Variant"] == "TestVariant"
+            assert event_properties["ETag"] == "cmwBRcIAq1jUyKL3Kj8bvf9jtxBrFg-R-ayExStMC90"
             assert (
-                mock_track_event.call_args[0][1]["FeatureFlagReference"]
+                event_properties["FeatureFlagReference"]
                 == "fake-store-uri/kv/.appconfig.featureflag/TestFeature"
             )
-            assert mock_track_event.call_args[0][1]["FeatureFlagId"] == "fake-feature-flag-id"
+            assert event_properties["FeatureFlagId"] == "fake-feature-flag-id"
+
+    def test_track_event_preserves_reserved_custom_event_name(self):
+        with patch("featuremanagement.azuremonitor._send_telemetry._initialize_event_logger"), patch(
+            "featuremanagement.azuremonitor._send_telemetry._event_logger.info"
+        ) as mock_event_logger_info, patch(
+            "featuremanagement.azuremonitor._send_telemetry.HAS_OPENTELEMETRY_LOGGING", True
+        ):
+            featuremanagement.azuremonitor._send_telemetry.track_event(
+                "FeatureEvaluation",
+                "test_user",
+                {
+                    "microsoft.custom_event.name": "override_attempt",
+                    "CustomProperty": "custom_value",
+                },
+            )
+
+            mock_event_logger_info.assert_called_once()
+            assert mock_event_logger_info.call_args[0][0] == "FeatureEvaluation"
+            assert mock_event_logger_info.call_args.kwargs["extra"]["microsoft.custom_event.name"] == "FeatureEvaluation"
+            assert mock_event_logger_info.call_args.kwargs["extra"]["CustomProperty"] == "custom_value"
+            assert mock_event_logger_info.call_args.kwargs["extra"]["TargetingId"] == "test_user"
 
     def test_send_telemetry_appinsights_no_user(self):
         feature_flag = FeatureFlag.convert_from_json({"id": "TestFeature"})
@@ -67,18 +93,20 @@ def test_send_telemetry_appinsights_no_user(self):
         evaluation_event.variant = variant
         evaluation_event.reason = VariantAssignmentReason.DEFAULT_WHEN_DISABLED
 
-        with patch("featuremanagement.azuremonitor._send_telemetry.azure_monitor_track_event") as mock_track_event:
+        with patch("featuremanagement.azuremonitor._send_telemetry.track_event") as mock_track_event:
             # This is called like this so we can override the track_event function
             featuremanagement.azuremonitor._send_telemetry.publish_telemetry(  # pylint: disable=protected-access
                 evaluation_event
             )
             mock_track_event.assert_called_once()
             assert mock_track_event.call_args[0][0] == "FeatureEvaluation"
-            assert mock_track_event.call_args[0][1]["FeatureName"] == "TestFeature"
-            assert mock_track_event.call_args[0][1]["Enabled"] == "False"
-            assert "TargetingId" not in mock_track_event.call_args[0][1]
-            assert mock_track_event.call_args[0][1]["Variant"] == "TestVariant"
-            assert mock_track_event.call_args[0][1]["VariantAssignmentReason"] == "DefaultWhenDisabled"
+            assert mock_track_event.call_args[0][1] == ""
+            event_properties = _event_properties(mock_track_event)
+            assert event_properties["FeatureName"] == "TestFeature"
+            assert event_properties["Enabled"] == "False"
+            assert "TargetingId" not in event_properties
+            assert event_properties["Variant"] == "TestVariant"
+            assert event_properties["VariantAssignmentReason"] == "DefaultWhenDisabled"
 
     def test_send_telemetry_appinsights_no_variant(self):
         feature_flag = FeatureFlag.convert_from_json({"id": "TestFeature"})
@@ -87,25 +115,26 @@ def test_send_telemetry_appinsights_no_variant(self):
         evaluation_event.enabled = True
         evaluation_event.user = "test_user"
 
-        with patch("featuremanagement.azuremonitor._send_telemetry.azure_monitor_track_event") as mock_track_event:
+        with patch("featuremanagement.azuremonitor._send_telemetry.track_event") as mock_track_event:
             # This is called like this so we can override the track_event function
             featuremanagement.azuremonitor._send_telemetry.publish_telemetry(  # pylint: disable=protected-access
                 evaluation_event
             )
             mock_track_event.assert_called_once()
             assert mock_track_event.call_args[0][0] == "FeatureEvaluation"
-            assert mock_track_event.call_args[0][1]["FeatureName"] == "TestFeature"
-            assert mock_track_event.call_args[0][1]["Enabled"] == "True"
-            assert mock_track_event.call_args[0][1]["TargetingId"] == "test_user"
-            assert "Variant" not in mock_track_event.call_args[0][1]
-            assert "Reason" not in mock_track_event.call_args[0][1]
+            assert mock_track_event.call_args[0][1] == "test_user"
+            event_properties = _event_properties(mock_track_event)
+            assert event_properties["FeatureName"] == "TestFeature"
+            assert event_properties["Enabled"] == "True"
+            assert "Variant" not in event_properties
+            assert "Reason" not in event_properties
 
     def test_send_telemetry_appinsights_no_feature_flag(self):
         evaluation_event = EvaluationEvent(None)
         evaluation_event.enabled = True
         evaluation_event.user = "test_user"
 
-        with patch("featuremanagement.azuremonitor._send_telemetry.azure_monitor_track_event") as mock_track_event:
+        with patch("featuremanagement.azuremonitor._send_telemetry.track_event") as mock_track_event:
             # This is called like this so we can override the track_event function
             featuremanagement.azuremonitor._send_telemetry.publish_telemetry(  # pylint: disable=protected-access
                 evaluation_event
@@ -130,18 +159,19 @@ def test_send_telemetry_appinsights_default_when_enabled(self):
         evaluation_event.variant = variant
         evaluation_event.reason = VariantAssignmentReason.DEFAULT_WHEN_ENABLED
 
-        with patch("featuremanagement.azuremonitor._send_telemetry.azure_monitor_track_event") as mock_track_event:
+        with patch("featuremanagement.azuremonitor._send_telemetry.track_event") as mock_track_event:
             # This is called like this so we can override the track_event function
             featuremanagement.azuremonitor._send_telemetry.publish_telemetry(  # pylint: disable=protected-access
                 evaluation_event
             )
             mock_track_event.assert_called_once()
             assert mock_track_event.call_args[0][0] == "FeatureEvaluation"
-            assert mock_track_event.call_args[0][1]["FeatureName"] == "TestFeature"
-            assert mock_track_event.call_args[0][1]["Enabled"] == "True"
-            assert mock_track_event.call_args[0][1]["TargetingId"] == "test_user"
-            assert mock_track_event.call_args[0][1]["Variant"] == "big"
-            assert mock_track_event.call_args[0][1]["VariantAssignmentReason"] == "DefaultWhenEnabled"
+            assert mock_track_event.call_args[0][1] == "test_user"
+            event_properties = _event_properties(mock_track_event)
+            assert event_properties["FeatureName"] == "TestFeature"
+            assert event_properties["Enabled"] == "True"
+            assert event_properties["Variant"] == "big"
+            assert event_properties["VariantAssignmentReason"] == "DefaultWhenEnabled"
 
     def test_send_telemetry_appinsights_default_when_enabled_no_percentile(self):
         feature_flag = FeatureFlag.convert_from_json(
@@ -160,18 +190,19 @@ def test_send_telemetry_appinsights_default_when_enabled_no_percentile(self):
         evaluation_event.variant = variant
         evaluation_event.reason = VariantAssignmentReason.DEFAULT_WHEN_ENABLED
 
-        with patch("featuremanagement.azuremonitor._send_telemetry.azure_monitor_track_event") as mock_track_event:
+        with patch("featuremanagement.azuremonitor._send_telemetry.track_event") as mock_track_event:
             # This is called like this so we can override the track_event function
             featuremanagement.azuremonitor._send_telemetry.publish_telemetry(  # pylint: disable=protected-access
                 evaluation_event
             )
             mock_track_event.assert_called_once()
             assert mock_track_event.call_args[0][0] == "FeatureEvaluation"
-            assert mock_track_event.call_args[0][1]["FeatureName"] == "TestFeature"
-            assert mock_track_event.call_args[0][1]["Enabled"] == "True"
-            assert mock_track_event.call_args[0][1]["TargetingId"] == "test_user"
-            assert mock_track_event.call_args[0][1]["Variant"] == "big"
-            assert mock_track_event.call_args[0][1]["VariantAssignmentReason"] == "DefaultWhenEnabled"
+            assert mock_track_event.call_args[0][1] == "test_user"
+            event_properties = _event_properties(mock_track_event)
+            assert event_properties["FeatureName"] == "TestFeature"
+            assert event_properties["Enabled"] == "True"
+            assert event_properties["Variant"] == "big"
+            assert event_properties["VariantAssignmentReason"] == "DefaultWhenEnabled"
 
     def test_send_telemetry_appinsights_allocation(self):
         feature_flag = FeatureFlag.convert_from_json(
@@ -190,20 +221,21 @@ def test_send_telemetry_appinsights_allocation(self):
         evaluation_event.variant = variant
         evaluation_event.reason = VariantAssignmentReason.PERCENTILE
 
-        with patch("featuremanagement.azuremonitor._send_telemetry.azure_monitor_track_event") as mock_track_event:
+        with patch("featuremanagement.azuremonitor._send_telemetry.track_event") as mock_track_event:
             # This is called like this so we can override the track_event function
             featuremanagement.azuremonitor._send_telemetry.publish_telemetry(  # pylint: disable=protected-access
                 evaluation_event
             )
             mock_track_event.assert_called_once()
             assert mock_track_event.call_args[0][0] == "FeatureEvaluation"
-            assert mock_track_event.call_args[0][1]["FeatureName"] == "TestFeature"
-            assert mock_track_event.call_args[0][1]["Enabled"] == "True"
-            assert mock_track_event.call_args[0][1]["TargetingId"] == "test_user"
-            assert mock_track_event.call_args[0][1]["Variant"] == "big"
-            assert mock_track_event.call_args[0][1]["VariantAssignmentReason"] == "Percentile"
-            assert mock_track_event.call_args[0][1]["VariantAssignmentPercentage"] == "25"
-            assert "DefaultWhenEnabled" not in mock_track_event.call_args[0][1]
+            assert mock_track_event.call_args[0][1] == "test_user"
+            event_properties = _event_properties(mock_track_event)
+            assert event_properties["FeatureName"] == "TestFeature"
+            assert event_properties["Enabled"] == "True"
+            assert event_properties["Variant"] == "big"
+            assert event_properties["VariantAssignmentReason"] == "Percentile"
+            assert event_properties["VariantAssignmentPercentage"] == "25"
+            assert "DefaultWhenEnabled" not in event_properties
 
     def test_targeting_span_processor(self, caplog):
         processor = TargetingSpanProcessor()