fix: early OpenTelemetry context propagation in invocation

runtimes/v1/azure_functions_runtime_v1/handle_event.py

@@ -156,6 +156,15 @@ async def invocation_request(request):
         fi: FunctionInfo = _functions.get_function(
             function_id)
         assert fi is not None
+
+        # Initialize context and configure OpenTelemetry before emitting
+        # invocation-scoped logs so they include trace context (Operation Id)
+        fi_context = get_context(invoc_request, fi.name,
+                                 fi.directory)
+        if (otel_manager.get_azure_monitor_available()
+                or otel_manager.get_otel_libs_available()):
+            configure_opentelemetry(fi_context)
+
         logger.info("Function name: %s, Function Type: %s",
                     fi.name,
                     ("async" if fi.is_async else "sync"))
@@ -174,9 +183,6 @@ async def invocation_request(request):
                 pb,
                 trigger_metadata=trigger_metadata)
 
-        fi_context = get_context(invoc_request, fi.name,
-                                 fi.directory)
-
         # Use local thread storage to store the invocation ID
         # for a customer's threads
         fi_context.thread_local_storage.invocation_id = invocation_id
@@ -188,9 +194,6 @@ async def invocation_request(request):
                 args[name] = Out()
 
         if fi.is_async:
-            if otel_manager.get_azure_monitor_available():
-                configure_opentelemetry(fi_context)
-
             # Not supporting Extensions
             call_result = await execute_async(fi.func, args)
         else:

runtimes/v1/tests/unittests/test_opentelemetry.py

@@ -4,13 +4,15 @@
 
 import tests.protos as protos
 
-from azure_functions_runtime_v1.handle_event import otel_manager, worker_init_request
+from azure_functions_runtime_v1.handle_event import (otel_manager, worker_init_request,
+                                                       invocation_request)
 from azure_functions_runtime_v1.otel import (initialize_azure_monitor,
                                              update_opentelemetry_status)
 from azure_functions_runtime_v1.logging import logger
 from tests.utils.constants import UNIT_TESTS_FOLDER
 from tests.utils.mock_classes import FunctionRequest, Request, WorkerRequest
-from unittest.mock import MagicMock, patch
+from tests.utils import testutils
+from unittest.mock import AsyncMock, MagicMock, patch
 
 
 FUNCTION_APP_DIRECTORY = UNIT_TESTS_FOLDER / 'basic_functions'
@@ -207,3 +209,138 @@ async def test_init_request_enable_azure_monitor_disabled_app_setting(
         # Verify that WorkerOpenTelemetryEnabled capability is not set
         capabilities = init_response.capabilities
         self.assertNotIn("WorkerOpenTelemetryEnabled", capabilities)
+
+
+class TestOpenTelemetryContextPropagation(testutils.AsyncTestCase):
+    """Tests to verify OpenTelemetry context is propagated before logging in v1.
+
+    Issue #1626: OpenTelemetry context must be configured before the first
+    log is emitted in invocation_request to ensure all logs have proper
+    Operation Id in Application Insights.
+    """
+
+    def setUp(self):
+        self.call_order = []
+
+    def _track_configure_otel(self, *args, **kwargs):
+        self.call_order.append('configure_opentelemetry')
+
+    def _track_logger_info(self, *args, **kwargs):
+        self.call_order.append('logger_info')
+
+    def _make_mock_request(self, invocation_id="test-inv-id",
+                           function_id="test-func-id"):
+        """Create a minimal mock invocation request."""
+        mock_invoc = MagicMock()
+        mock_invoc.invocation_id = invocation_id
+        mock_invoc.function_id = function_id
+        mock_invoc.input_data = []
+
+        mock_request = MagicMock()
+        mock_request.request.invocation_request = mock_invoc
+        return mock_request
+
+    def _make_mock_fi(self):
+        """Create a minimal mock FunctionInfo."""
+        mock_fi = MagicMock()
+        mock_fi.name = "test_function"
+        mock_fi.is_async = True
+        mock_fi.directory = "/test/dir"
+        mock_fi.input_types = {}
+        mock_fi.output_types = {}
+        mock_fi.requires_context = False
+        mock_fi.has_return = False
+        mock_fi.return_type = None
+        return mock_fi
+
+    @patch("azure_functions_runtime_v1.handle_event"
+           ".otel_manager.get_azure_monitor_available", return_value=True)
+    @patch("azure_functions_runtime_v1.handle_event"
+           ".otel_manager.get_otel_libs_available", return_value=False)
+    @patch("azure_functions_runtime_v1.handle_event.execute_async",
+           new_callable=AsyncMock)
+    @patch("azure_functions_runtime_v1.handle_event.get_context")
+    @patch("azure_functions_runtime_v1.handle_event._functions")
+    @patch("azure_functions_runtime_v1.handle_event.configure_opentelemetry")
+    @patch("azure_functions_runtime_v1.handle_event.logger")
+    async def test_otel_configured_before_first_log_azure_monitor(
+        self,
+        mock_logger,
+        mock_configure_otel,
+        mock_functions,
+        mock_get_context,
+        mock_execute_async,
+        mock_get_otel_libs,
+        mock_get_azure_monitor,
+    ):
+        """Verify configure_opentelemetry is called before first log (Azure Monitor)."""
+        mock_logger.info.side_effect = self._track_logger_info
+        mock_configure_otel.side_effect = self._track_configure_otel
+        mock_functions.get_function.return_value = self._make_mock_fi()
+        mock_get_context.return_value = MagicMock()
+        mock_execute_async.return_value = None
+
+        try:
+            await invocation_request(self._make_mock_request())
+        except Exception:
+            pass
+
+        self.assertIn('configure_opentelemetry', self.call_order,
+                      "configure_opentelemetry should have been called")
+        self.assertIn('logger_info', self.call_order,
+                      "logger.info should have been called")
+
+        otel_index = self.call_order.index('configure_opentelemetry')
+        first_log_index = self.call_order.index('logger_info')
+        self.assertLess(
+            otel_index, first_log_index,
+            f"configure_opentelemetry (index {otel_index}) should be called "
+            f"before the first logger.info (index {first_log_index}). "
+            f"Call order: {self.call_order}"
+        )
+
+    @patch("azure_functions_runtime_v1.handle_event"
+           ".otel_manager.get_azure_monitor_available", return_value=False)
+    @patch("azure_functions_runtime_v1.handle_event"
+           ".otel_manager.get_otel_libs_available", return_value=True)
+    @patch("azure_functions_runtime_v1.handle_event.execute_async",
+           new_callable=AsyncMock)
+    @patch("azure_functions_runtime_v1.handle_event.get_context")
+    @patch("azure_functions_runtime_v1.handle_event._functions")
+    @patch("azure_functions_runtime_v1.handle_event.configure_opentelemetry")
+    @patch("azure_functions_runtime_v1.handle_event.logger")
+    async def test_otel_configured_before_first_log_otel_libs(
+        self,
+        mock_logger,
+        mock_configure_otel,
+        mock_functions,
+        mock_get_context,
+        mock_execute_async,
+        mock_get_otel_libs,
+        mock_get_azure_monitor,
+    ):
+        """Verify configure_opentelemetry is called before first log (otel libs)."""
+        mock_logger.info.side_effect = self._track_logger_info
+        mock_configure_otel.side_effect = self._track_configure_otel
+        mock_functions.get_function.return_value = self._make_mock_fi()
+        mock_get_context.return_value = MagicMock()
+        mock_execute_async.return_value = None
+
+        try:
+            await invocation_request(self._make_mock_request())
+        except Exception:
+            pass
+
+        self.assertIn('configure_opentelemetry', self.call_order,
+                      "configure_opentelemetry should have been called")
+        self.assertIn('logger_info', self.call_order,
+                      "logger.info should have been called")
+
+        otel_index = self.call_order.index('configure_opentelemetry')
+        first_log_index = self.call_order.index('logger_info')
+        self.assertLess(
+            otel_index, first_log_index,
+            f"configure_opentelemetry (index {otel_index}) should be called "
+            f"before the first logger.info (index {first_log_index}). "
+            f"Call order: {self.call_order}"
+        )

runtimes/v2/azure_functions_runtime/handle_event.py

@@ -182,6 +182,15 @@ async def invocation_request(request):
         fi: FunctionInfo = _functions.get_function(
             function_id)
         assert fi is not None
+
+        # Initialize context and configure OpenTelemetry before emitting
+        # invocation-scoped logs so they include trace context (Operation Id)
+        fi_context = get_context(invoc_request, fi.name,
+                                 fi.directory)
+        if (otel_manager.get_azure_monitor_available()
+                or otel_manager.get_otel_libs_available()):
+            configure_opentelemetry(fi_context)
+
         logger.info("Function name: %s, Function Type: %s",
                     fi.name,
                     ("async" if fi.is_async else "sync"))
@@ -217,9 +226,6 @@ async def invocation_request(request):
             await sync_http_request(http_request, func_http_request)
             args[trigger_arg_name] = http_request
 
-        fi_context = get_context(invoc_request, fi.name,
-                                 fi.directory)
-
         # Use local thread storage to store the invocation ID
         # for a customer's threads
         fi_context.thread_local_storage.invocation_id = invocation_id
@@ -234,10 +240,6 @@ async def invocation_request(request):
                 args[name] = Out()
 
         if fi.is_async:
-            if (otel_manager.get_azure_monitor_available()
-                    or otel_manager.get_otel_libs_available()):
-                configure_opentelemetry(fi_context)
-
             # Extensions are not supported
             call_result = await execute_async(fi.func, args)
         else:

runtimes/v2/tests/unittests/test_opentelemetry.py

@@ -4,14 +4,16 @@
 
 import tests.protos as protos
 
-from azure_functions_runtime.handle_event import otel_manager, worker_init_request
+from azure_functions_runtime.handle_event import (otel_manager, worker_init_request,
+                                                    invocation_request)
 from azure_functions_runtime.otel import (initialize_azure_monitor,
                                           update_opentelemetry_status,
                                           OTelManager)
 from azure_functions_runtime.logging import logger
 from tests.utils.constants import UNIT_TESTS_FOLDER
 from tests.utils.mock_classes import FunctionRequest, Request, WorkerRequest
-from unittest.mock import MagicMock, patch
+from tests.utils import testutils
+from unittest.mock import AsyncMock, MagicMock, patch
 
 
 FUNCTION_APP_DIRECTORY = UNIT_TESTS_FOLDER / 'basic_functions'
@@ -242,3 +244,140 @@ def test_set_and_get_trace_context_propagator(self):
         dummy_propagator = object()
         self.manager.set_trace_context_propagator(dummy_propagator)
         self.assertIs(self.manager.get_trace_context_propagator(), dummy_propagator)
+
+
+class TestOpenTelemetryContextPropagation(testutils.AsyncTestCase):
+    """Tests to verify OpenTelemetry context is propagated before logging in v2.
+
+    Issue #1626: OpenTelemetry context must be configured before the first
+    log is emitted in invocation_request to ensure all logs have proper
+    Operation Id in Application Insights.
+    """
+
+    def setUp(self):
+        self.call_order = []
+
+    def _track_configure_otel(self, *args, **kwargs):
+        self.call_order.append('configure_opentelemetry')
+
+    def _track_logger_info(self, *args, **kwargs):
+        self.call_order.append('logger_info')
+
+    def _make_mock_request(self, invocation_id="test-inv-id",
+                           function_id="test-func-id"):
+        """Create a minimal mock invocation request."""
+        mock_invoc = MagicMock()
+        mock_invoc.invocation_id = invocation_id
+        mock_invoc.function_id = function_id
+        mock_invoc.input_data = []
+
+        mock_request = MagicMock()
+        mock_request.request.invocation_request = mock_invoc
+        return mock_request
+
+    def _make_mock_fi(self):
+        """Create a minimal mock FunctionInfo."""
+        mock_fi = MagicMock()
+        mock_fi.name = "test_function"
+        mock_fi.is_async = True
+        mock_fi.directory = "/test/dir"
+        mock_fi.input_types = {}
+        mock_fi.output_types = {}
+        mock_fi.requires_context = False
+        mock_fi.has_return = False
+        mock_fi.return_type = None
+        mock_fi.settlement_client_arg = None
+        mock_fi.is_http_func = False
+        return mock_fi
+
+    @patch("azure_functions_runtime.handle_event"
+           ".otel_manager.get_azure_monitor_available", return_value=True)
+    @patch("azure_functions_runtime.handle_event"
+           ".otel_manager.get_otel_libs_available", return_value=False)
+    @patch("azure_functions_runtime.handle_event.execute_async",
+           new_callable=AsyncMock)
+    @patch("azure_functions_runtime.handle_event.get_context")
+    @patch("azure_functions_runtime.handle_event._functions")
+    @patch("azure_functions_runtime.handle_event.configure_opentelemetry")
+    @patch("azure_functions_runtime.handle_event.logger")
+    async def test_otel_configured_before_first_log_azure_monitor(
+        self,
+        mock_logger,
+        mock_configure_otel,
+        mock_functions,
+        mock_get_context,
+        mock_execute_async,
+        mock_get_otel_libs,
+        mock_get_azure_monitor,
+    ):
+        """Verify configure_opentelemetry is called before first log (Azure Monitor)."""
+        mock_logger.info.side_effect = self._track_logger_info
+        mock_configure_otel.side_effect = self._track_configure_otel
+        mock_functions.get_function.return_value = self._make_mock_fi()
+        mock_get_context.return_value = MagicMock()
+        mock_execute_async.return_value = None
+
+        try:
+            await invocation_request(self._make_mock_request())
+        except Exception:
+            pass
+
+        self.assertIn('configure_opentelemetry', self.call_order,
+                      "configure_opentelemetry should have been called")
+        self.assertIn('logger_info', self.call_order,
+                      "logger.info should have been called")
+
+        otel_index = self.call_order.index('configure_opentelemetry')
+        first_log_index = self.call_order.index('logger_info')
+        self.assertLess(
+            otel_index, first_log_index,
+            f"configure_opentelemetry (index {otel_index}) should be called "
+            f"before the first logger.info (index {first_log_index}). "
+            f"Call order: {self.call_order}"
+        )
+
+    @patch("azure_functions_runtime.handle_event"
+           ".otel_manager.get_azure_monitor_available", return_value=False)
+    @patch("azure_functions_runtime.handle_event"
+           ".otel_manager.get_otel_libs_available", return_value=True)
+    @patch("azure_functions_runtime.handle_event.execute_async",
+           new_callable=AsyncMock)
+    @patch("azure_functions_runtime.handle_event.get_context")
+    @patch("azure_functions_runtime.handle_event._functions")
+    @patch("azure_functions_runtime.handle_event.configure_opentelemetry")
+    @patch("azure_functions_runtime.handle_event.logger")
+    async def test_otel_configured_before_first_log_otel_libs(
+        self,
+        mock_logger,
+        mock_configure_otel,
+        mock_functions,
+        mock_get_context,
+        mock_execute_async,
+        mock_get_otel_libs,
+        mock_get_azure_monitor,
+    ):
+        """Verify configure_opentelemetry is called before first log (otel libs)."""
+        mock_logger.info.side_effect = self._track_logger_info
+        mock_configure_otel.side_effect = self._track_configure_otel
+        mock_functions.get_function.return_value = self._make_mock_fi()
+        mock_get_context.return_value = MagicMock()
+        mock_execute_async.return_value = None
+
+        try:
+            await invocation_request(self._make_mock_request())
+        except Exception:
+            pass
+
+        self.assertIn('configure_opentelemetry', self.call_order,
+                      "configure_opentelemetry should have been called")
+        self.assertIn('logger_info', self.call_order,
+                      "logger.info should have been called")
+
+        otel_index = self.call_order.index('configure_opentelemetry')
+        first_log_index = self.call_order.index('logger_info')
+        self.assertLess(
+            otel_index, first_log_index,
+            f"configure_opentelemetry (index {otel_index}) should be called "
+            f"before the first logger.info (index {first_log_index}). "
+            f"Call order: {self.call_order}"
+        )