diff --git a/eng/pack/Microsoft.Azure.Functions.V4.PythonWorker.nuspec b/eng/pack/Microsoft.Azure.Functions.V4.PythonWorker.nuspec
index 6432af7a0..b87756372 100644
--- a/eng/pack/Microsoft.Azure.Functions.V4.PythonWorker.nuspec
+++ b/eng/pack/Microsoft.Azure.Functions.V4.PythonWorker.nuspec
@@ -10,6 +10,12 @@
© .NET Foundation. All rights reserved.
+
+
+
+
+
+
diff --git a/eng/templates/jobs/ci-dependency-check.yml b/eng/templates/jobs/ci-dependency-check.yml
index 38f368f74..cbebc80e0 100644
--- a/eng/templates/jobs/ci-dependency-check.yml
+++ b/eng/templates/jobs/ci-dependency-check.yml
@@ -12,6 +12,8 @@ jobs:
strategy:
matrix:
+ Python39:
+ PYTHON_VERSION: '3.9'
Python310:
PYTHON_VERSION: '3.10'
Python311:
diff --git a/eng/templates/jobs/ci-emulator-tests.yml b/eng/templates/jobs/ci-emulator-tests.yml
index 8464900aa..d4da5446e 100644
--- a/eng/templates/jobs/ci-emulator-tests.yml
+++ b/eng/templates/jobs/ci-emulator-tests.yml
@@ -15,6 +15,8 @@ jobs:
strategy:
matrix:
+ Python39:
+ PYTHON_VERSION: '3.9'
Python310:
PYTHON_VERSION: '3.10'
Python311:
diff --git a/eng/templates/jobs/ci-unit-tests.yml b/eng/templates/jobs/ci-unit-tests.yml
index 57a4925ae..b5a3ecae9 100644
--- a/eng/templates/jobs/ci-unit-tests.yml
+++ b/eng/templates/jobs/ci-unit-tests.yml
@@ -12,6 +12,8 @@ jobs:
strategy:
matrix:
+ Python39:
+ PYTHON_VERSION: '3.9'
Python310:
PYTHON_VERSION: '3.10'
Python311:
diff --git a/eng/templates/official/jobs/build-artifacts.yml b/eng/templates/official/jobs/build-artifacts.yml
index c8df4955a..b62f3e6e8 100644
--- a/eng/templates/official/jobs/build-artifacts.yml
+++ b/eng/templates/official/jobs/build-artifacts.yml
@@ -7,6 +7,9 @@ jobs:
os: windows
strategy:
matrix:
+ Python39V4:
+ pythonVersion: '3.9'
+ normalizedPythonVersion: '3.9'
Python310V4:
pythonVersion: '3.10'
normalizedPythonVersion: '3.10'
@@ -43,6 +46,9 @@ jobs:
os: windows
strategy:
matrix:
+ Python39V4:
+ pythonVersion: '3.9'
+ normalizedPythonVersion: '3.9'
Python310V4:
pythonVersion: '3.10'
normalizedPythonVersion: '3.10'
@@ -79,6 +85,9 @@ jobs:
os: linux
strategy:
matrix:
+ Python39V4:
+ pythonVersion: '3.9'
+ normalizedPythonVersion: '3.9'
Python310V4:
pythonVersion: '3.10'
normalizedPythonVersion: '3.10'
@@ -372,6 +381,9 @@ jobs:
os: macOS
strategy:
matrix:
+ Python39V4:
+ pythonVersion: '3.9'
+ normalizedPythonVersion: '3.9'
Python310V4:
pythonVersion: '3.10'
normalizedPythonVersion: '3.10'
@@ -407,6 +419,9 @@ jobs:
os: macOS
strategy:
matrix:
+ Python39V4:
+ pythonVersion: '3.9'
+ normalizedPythonVersion: '3.9'
Python310V4:
pythonVersion: '3.10'
normalizedPythonVersion: '3.10'
@@ -442,6 +457,9 @@ jobs:
os: linux
strategy:
matrix:
+ Python39V4:
+ pythonVersion: '3.9'
+ normalizedPythonVersion: '3.9'
Python310V4:
pythonVersion: '3.10'
normalizedPythonVersion: '3.10'
diff --git a/eng/templates/official/jobs/ci-docker-dedicated-tests.yml b/eng/templates/official/jobs/ci-docker-dedicated-tests.yml
index ba25ec208..d13762758 100644
--- a/eng/templates/official/jobs/ci-docker-dedicated-tests.yml
+++ b/eng/templates/official/jobs/ci-docker-dedicated-tests.yml
@@ -12,6 +12,12 @@ jobs:
strategy:
matrix:
+ Python39:
+ PYTHON_VERSION: '3.9'
+ STORAGE_CONNECTION: $(LinuxStorageConnectionString39)
+ SQL_CONNECTION: $(LinuxSqlConnectionString39)
+ EVENTGRID_URI: $(LinuxEventGridTopicUriString39)
+ EVENTGRID_CONNECTION: $(LinuxEventGridConnectionKeyString39)
Python310:
PYTHON_VERSION: '3.10'
STORAGE_CONNECTION: $(LinuxStorageConnectionString310)
diff --git a/eng/templates/official/jobs/ci-e2e-tests.yml b/eng/templates/official/jobs/ci-e2e-tests.yml
index eb9b49c7b..27767f7e6 100644
--- a/eng/templates/official/jobs/ci-e2e-tests.yml
+++ b/eng/templates/official/jobs/ci-e2e-tests.yml
@@ -13,6 +13,12 @@ jobs:
strategy:
matrix:
+ Python39:
+ PYTHON_VERSION: '3.9'
+ STORAGE_CONNECTION: $(LinuxStorageConnectionString39)
+ SQL_CONNECTION: $(LinuxSqlConnectionString39)
+ EVENTGRID_URI: $(LinuxEventGridTopicUriString39)
+ EVENTGRID_CONNECTION: $(LinuxEventGridConnectionKeyString39)
Python310:
PYTHON_VERSION: '3.10'
STORAGE_CONNECTION: $(LinuxStorageConnectionString310)
diff --git a/runtimes/v1/azure_functions_runtime_v1/handle_event.py b/runtimes/v1/azure_functions_runtime_v1/handle_event.py
index b42793c58..da3b39e2f 100644
--- a/runtimes/v1/azure_functions_runtime_v1/handle_event.py
+++ b/runtimes/v1/azure_functions_runtime_v1/handle_event.py
@@ -11,10 +11,7 @@
from .functions import FunctionInfo, Registry
from .loader import load_function, install
from .logging import logger
-from .otel import (configure_opentelemetry,
- initialize_azure_monitor,
- otel_manager,
- update_opentelemetry_status)
+from .otel import otel_manager, initialize_azure_monitor, configure_opentelemetry
from .version import VERSION
from .bindings.context import get_context
@@ -73,7 +70,6 @@ async def worker_init_request(request):
if is_envvar_true(PYTHON_ENABLE_OPENTELEMETRY):
otel_manager.set_otel_libs_available(True)
- update_opentelemetry_status()
if (otel_manager.get_azure_monitor_available()
or otel_manager.get_otel_libs_available()):
@@ -160,15 +156,6 @@ 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"))
@@ -187,6 +174,9 @@ 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
@@ -198,6 +188,9 @@ 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:
@@ -239,6 +232,7 @@ async def invocation_request(request):
# Actively flush customer print() function to console
sys.stdout.flush()
+
logger.debug("Successfully completed WorkerInvocationRequest.")
return protos.InvocationResponse(
invocation_id=invocation_id,
@@ -297,7 +291,6 @@ async def function_environment_reload_request(request):
capabilities = {}
if is_envvar_true(PYTHON_ENABLE_OPENTELEMETRY):
otel_manager.set_otel_libs_available(True)
- update_opentelemetry_status()
if is_envvar_true(PYTHON_APPLICATIONINSIGHTS_ENABLE_TELEMETRY):
initialize_azure_monitor()
diff --git a/runtimes/v1/azure_functions_runtime_v1/otel.py b/runtimes/v1/azure_functions_runtime_v1/otel.py
index 2e579a85d..a73502c15 100644
--- a/runtimes/v1/azure_functions_runtime_v1/otel.py
+++ b/runtimes/v1/azure_functions_runtime_v1/otel.py
@@ -107,15 +107,10 @@ def initialize_azure_monitor():
def configure_opentelemetry(invocation_context):
- trace_context_propagator = otel_manager.get_trace_context_propagator()
- context_api = otel_manager.get_context_api()
- if trace_context_propagator is None or context_api is None:
- return
-
carrier = {TRACEPARENT: invocation_context.trace_context.trace_parent,
TRACESTATE: invocation_context.trace_context.trace_state}
- ctx = trace_context_propagator.extract(carrier)
- context_api.attach(ctx)
+ ctx = otel_manager.get_trace_context_propagator().extract(carrier)
+ otel_manager.get_context_api().attach(ctx)
otel_manager = OTelManager()
diff --git a/runtimes/v1/azure_functions_runtime_v1/utils/executor.py b/runtimes/v1/azure_functions_runtime_v1/utils/executor.py
index 15675327f..12dd04e40 100644
--- a/runtimes/v1/azure_functions_runtime_v1/utils/executor.py
+++ b/runtimes/v1/azure_functions_runtime_v1/utils/executor.py
@@ -7,6 +7,8 @@
from typing import Any
+from ..otel import otel_manager, configure_opentelemetry
+
def get_current_loop():
return asyncio.events.get_event_loop()
@@ -29,6 +31,8 @@ def run_sync_func(invocation_id, context, func, params):
context.thread_local_storage.invocation_id = invocation_id
token = invocation_id_cv.set(invocation_id)
try:
+ if otel_manager.get_azure_monitor_available():
+ configure_opentelemetry(context)
result = functools.partial(execute_sync, func)
return result(params)
finally:
diff --git a/runtimes/v1/tests/unittests/test_executor.py b/runtimes/v1/tests/unittests/test_executor.py
deleted file mode 100644
index 1acbc2bea..000000000
--- a/runtimes/v1/tests/unittests/test_executor.py
+++ /dev/null
@@ -1,57 +0,0 @@
-import concurrent.futures
-import threading
-import unittest
-from unittest.mock import MagicMock
-
-from azure_functions_runtime_v1.utils.executor import (
- invocation_id_cv,
- run_sync_func,
-)
-
-
-class TestSyncInvocationContext(unittest.TestCase):
-
- def setUp(self):
- self.context = MagicMock()
- self.context.thread_local_storage = threading.local()
- self.executor = concurrent.futures.ThreadPoolExecutor(max_workers=1)
-
- def tearDown(self):
- self.executor.shutdown()
-
- def _get_current_invocation_ids(self):
- return (self.context.thread_local_storage.invocation_id,
- invocation_id_cv.get())
-
- def test_invocation_id_cleared_after_success(self):
- observed_invocation_ids = []
-
- def invoke():
- observed_invocation_ids.append(self._get_current_invocation_ids())
-
- self.executor.submit(
- run_sync_func,
- 'test-invocation', self.context, invoke, {}).result()
-
- remaining_invocation_ids = self.executor.submit(
- self._get_current_invocation_ids).result()
- self.assertEqual(
- observed_invocation_ids,
- [('test-invocation', 'test-invocation')])
- self.assertEqual(remaining_invocation_ids, (None, None))
-
- def test_invocation_id_cleared_after_exception(self):
- def invoke():
- self.assertEqual(
- self._get_current_invocation_ids(),
- ('test-invocation', 'test-invocation'))
- raise RuntimeError('test error')
-
- with self.assertRaisesRegex(RuntimeError, 'test error'):
- self.executor.submit(
- run_sync_func,
- 'test-invocation', self.context, invoke, {}).result()
-
- remaining_invocation_ids = self.executor.submit(
- self._get_current_invocation_ids).result()
- self.assertEqual(remaining_invocation_ids, (None, None))
diff --git a/runtimes/v1/tests/unittests/test_opentelemetry.py b/runtimes/v1/tests/unittests/test_opentelemetry.py
index 39b214539..f992ac85d 100644
--- a/runtimes/v1/tests/unittests/test_opentelemetry.py
+++ b/runtimes/v1/tests/unittests/test_opentelemetry.py
@@ -1,23 +1,16 @@
# Copyright (c) Microsoft Corporation. All rights reserved.
-import asyncio
import os
import unittest
import tests.protos as protos
-from azure_functions_runtime_v1.handle_event import (
- invocation_request,
- otel_manager,
- worker_init_request,
-)
-from azure_functions_runtime_v1.otel import (configure_opentelemetry,
- initialize_azure_monitor,
+from azure_functions_runtime_v1.handle_event import otel_manager, worker_init_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 tests.utils import testutils
-from unittest.mock import AsyncMock, MagicMock, patch
+from unittest.mock import MagicMock, patch
FUNCTION_APP_DIRECTORY = UNIT_TESTS_FOLDER / 'basic_functions'
@@ -25,24 +18,6 @@
class TestOpenTelemetry(unittest.TestCase):
- def setUp(self):
- self._otel_manager_state = (
- otel_manager.get_azure_monitor_available(),
- otel_manager.get_otel_libs_available(),
- otel_manager.get_context_api(),
- otel_manager.get_trace_context_propagator(),
- )
-
- def tearDown(self):
- (azure_monitor_available,
- otel_libs_available,
- context_api,
- trace_context_propagator) = self._otel_manager_state
- otel_manager.set_azure_monitor_available(azure_monitor_available)
- otel_manager.set_otel_libs_available(otel_libs_available)
- otel_manager.set_context_api(context_api)
- otel_manager.set_trace_context_propagator(trace_context_propagator)
-
def test_update_opentelemetry_status_import_error(self):
with patch.dict('sys.modules', {
'opentelemetry': None,
@@ -67,12 +42,6 @@ def test_update_opentelemetry_status_success(
self.assertIsNotNone(otel_manager.get_context_api())
self.assertIsNotNone(otel_manager.get_trace_context_propagator())
- def test_configure_opentelemetry_noops_when_not_initialized(self):
- otel_manager.set_context_api(None)
- otel_manager.set_trace_context_propagator(None)
-
- configure_opentelemetry(MagicMock())
-
@patch('builtins.__import__')
@patch("azure_functions_runtime_v1.otel.update_opentelemetry_status")
def test_initialize_azure_monitor_success(
@@ -176,7 +145,7 @@ async def test_init_request_initialize_azure_monitor_disabled_app_setting(
self.assertNotIn("WorkerOpenTelemetryEnabled", capabilities)
@patch.dict(os.environ, {'PYTHON_ENABLE_OPENTELEMETRY': 'true'})
- def test_init_request_enable_opentelemetry_enabled_app_setting(
+ async def test_init_request_enable_opentelemetry_enabled_app_setting(
self,
):
worker_request = WorkerRequest(name='worker_init_request',
@@ -185,15 +154,13 @@ def test_init_request_enable_opentelemetry_enabled_app_setting(
FUNCTION_APP_DIRECTORY)),
properties={'host': '123',
'protos': protos})
- init_response = asyncio.run(worker_init_request(worker_request))
+ init_response = await worker_init_request(worker_request)
self.assertEqual(init_response.result.status,
protos.StatusResult.Success)
- # Verify OpenTelemetry propagation is initialized
- self.assertTrue(otel_manager.get_otel_libs_available())
- self.assertIsNotNone(otel_manager.get_context_api())
- self.assertIsNotNone(otel_manager.get_trace_context_propagator())
+ # Verify otel_libs_available is set to True
+ self.assertTrue(otel_manager.get_azure_monitor_available())
# Verify that WorkerOpenTelemetryEnabled capability is set to _TRUE
capabilities = init_response.capabilities
self.assertIn("WorkerOpenTelemetryEnabled", capabilities)
@@ -240,188 +207,3 @@ 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}"
- )
-
- @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.run_sync_func",
- return_value=None)
- @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_sync_function(
- self,
- mock_logger,
- mock_configure_otel,
- mock_functions,
- mock_get_context,
- mock_run_sync_func,
- mock_get_otel_libs,
- mock_get_azure_monitor,
- ):
- """Verify configure_opentelemetry is called before first log (sync function)."""
- mock_logger.info.side_effect = self._track_logger_info
- mock_configure_otel.side_effect = self._track_configure_otel
- mock_fi = self._make_mock_fi()
- mock_fi.is_async = False
- mock_functions.get_function.return_value = mock_fi
- invocation_context = MagicMock()
- mock_get_context.return_value = invocation_context
- request = self._make_mock_request()
-
- try:
- await invocation_request(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")
- mock_configure_otel.assert_called_once_with(invocation_context)
-
- 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}"
- )
diff --git a/runtimes/v2/azure_functions_runtime/handle_event.py b/runtimes/v2/azure_functions_runtime/handle_event.py
index feab5964c..0ed133f93 100644
--- a/runtimes/v2/azure_functions_runtime/handle_event.py
+++ b/runtimes/v2/azure_functions_runtime/handle_event.py
@@ -18,10 +18,7 @@
)
from .loader import index_function_app, process_indexed_function
from .logging import logger
-from .otel import (configure_opentelemetry,
- initialize_azure_monitor,
- otel_manager,
- update_opentelemetry_status)
+from .otel import otel_manager, configure_opentelemetry, initialize_azure_monitor
from .version import VERSION
from .bindings.context import get_context
@@ -89,7 +86,6 @@ async def worker_init_request(request):
if is_envvar_true(PYTHON_ENABLE_OPENTELEMETRY):
otel_manager.set_otel_libs_available(True)
- update_opentelemetry_status()
if (otel_manager.get_azure_monitor_available()
or otel_manager.get_otel_libs_available()):
@@ -186,15 +182,6 @@ 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"))
@@ -230,6 +217,9 @@ 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
@@ -244,6 +234,10 @@ 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:
@@ -343,7 +337,6 @@ async def function_environment_reload_request(request):
capabilities = {}
if is_envvar_true(PYTHON_ENABLE_OPENTELEMETRY):
otel_manager.set_otel_libs_available(True)
- update_opentelemetry_status()
if is_envvar_true(PYTHON_APPLICATIONINSIGHTS_ENABLE_TELEMETRY):
initialize_azure_monitor()
diff --git a/runtimes/v2/azure_functions_runtime/otel.py b/runtimes/v2/azure_functions_runtime/otel.py
index c8b7ecb79..3f608fa50 100644
--- a/runtimes/v2/azure_functions_runtime/otel.py
+++ b/runtimes/v2/azure_functions_runtime/otel.py
@@ -107,15 +107,10 @@ def initialize_azure_monitor():
def configure_opentelemetry(invocation_context):
- trace_context_propagator = otel_manager.get_trace_context_propagator()
- context_api = otel_manager.get_context_api()
- if trace_context_propagator is None or context_api is None:
- return
-
carrier = {TRACEPARENT: invocation_context.trace_context.trace_parent,
TRACESTATE: invocation_context.trace_context.trace_state}
- ctx = trace_context_propagator.extract(carrier)
- context_api.attach(ctx)
+ ctx = otel_manager.get_trace_context_propagator().extract(carrier)
+ otel_manager.get_context_api().attach(ctx)
otel_manager = OTelManager()
diff --git a/runtimes/v2/azure_functions_runtime/utils/executor.py b/runtimes/v2/azure_functions_runtime/utils/executor.py
index 35da603da..718647ae6 100644
--- a/runtimes/v2/azure_functions_runtime/utils/executor.py
+++ b/runtimes/v2/azure_functions_runtime/utils/executor.py
@@ -6,6 +6,8 @@
from typing import Any
+from ..otel import otel_manager, configure_opentelemetry
+
def get_current_loop():
return asyncio.events.get_event_loop()
@@ -28,6 +30,9 @@ def run_sync_func(invocation_id, context, func, params):
context.thread_local_storage.invocation_id = invocation_id
token = invocation_id_cv.set(invocation_id)
try:
+ if (otel_manager.get_azure_monitor_available()
+ or otel_manager.get_otel_libs_available()):
+ configure_opentelemetry(context)
result = functools.partial(execute_sync, func)
return result(params)
finally:
diff --git a/runtimes/v2/tests/unittests/test_executor.py b/runtimes/v2/tests/unittests/test_executor.py
deleted file mode 100644
index 840d42784..000000000
--- a/runtimes/v2/tests/unittests/test_executor.py
+++ /dev/null
@@ -1,57 +0,0 @@
-import concurrent.futures
-import threading
-import unittest
-from unittest.mock import MagicMock
-
-from azure_functions_runtime.utils.executor import (
- invocation_id_cv,
- run_sync_func,
-)
-
-
-class TestSyncInvocationContext(unittest.TestCase):
-
- def setUp(self):
- self.context = MagicMock()
- self.context.thread_local_storage = threading.local()
- self.executor = concurrent.futures.ThreadPoolExecutor(max_workers=1)
-
- def tearDown(self):
- self.executor.shutdown()
-
- def _get_current_invocation_ids(self):
- return (self.context.thread_local_storage.invocation_id,
- invocation_id_cv.get())
-
- def test_invocation_id_cleared_after_success(self):
- observed_invocation_ids = []
-
- def invoke():
- observed_invocation_ids.append(self._get_current_invocation_ids())
-
- self.executor.submit(
- run_sync_func,
- 'test-invocation', self.context, invoke, {}).result()
-
- remaining_invocation_ids = self.executor.submit(
- self._get_current_invocation_ids).result()
- self.assertEqual(
- observed_invocation_ids,
- [('test-invocation', 'test-invocation')])
- self.assertEqual(remaining_invocation_ids, (None, None))
-
- def test_invocation_id_cleared_after_exception(self):
- def invoke():
- self.assertEqual(
- self._get_current_invocation_ids(),
- ('test-invocation', 'test-invocation'))
- raise RuntimeError('test error')
-
- with self.assertRaisesRegex(RuntimeError, 'test error'):
- self.executor.submit(
- run_sync_func,
- 'test-invocation', self.context, invoke, {}).result()
-
- remaining_invocation_ids = self.executor.submit(
- self._get_current_invocation_ids).result()
- self.assertEqual(remaining_invocation_ids, (None, None))
diff --git a/runtimes/v2/tests/unittests/test_opentelemetry.py b/runtimes/v2/tests/unittests/test_opentelemetry.py
index 2a144aee6..696dfcb55 100644
--- a/runtimes/v2/tests/unittests/test_opentelemetry.py
+++ b/runtimes/v2/tests/unittests/test_opentelemetry.py
@@ -1,24 +1,17 @@
# Copyright (c) Microsoft Corporation. All rights reserved.
-import asyncio
import os
import unittest
import tests.protos as protos
-from azure_functions_runtime.handle_event import (
- invocation_request,
- otel_manager,
- worker_init_request,
-)
-from azure_functions_runtime.otel import (configure_opentelemetry,
- initialize_azure_monitor,
+from azure_functions_runtime.handle_event import otel_manager, worker_init_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 tests.utils import testutils
-from unittest.mock import AsyncMock, MagicMock, patch
+from unittest.mock import MagicMock, patch
FUNCTION_APP_DIRECTORY = UNIT_TESTS_FOLDER / 'basic_functions'
@@ -26,24 +19,6 @@
class TestOpenTelemetry(unittest.TestCase):
- def setUp(self):
- self._otel_manager_state = (
- otel_manager.get_azure_monitor_available(),
- otel_manager.get_otel_libs_available(),
- otel_manager.get_context_api(),
- otel_manager.get_trace_context_propagator(),
- )
-
- def tearDown(self):
- (azure_monitor_available,
- otel_libs_available,
- context_api,
- trace_context_propagator) = self._otel_manager_state
- otel_manager.set_azure_monitor_available(azure_monitor_available)
- otel_manager.set_otel_libs_available(otel_libs_available)
- otel_manager.set_context_api(context_api)
- otel_manager.set_trace_context_propagator(trace_context_propagator)
-
def test_update_opentelemetry_status_import_error(self):
with patch.dict('sys.modules', {
'opentelemetry': None,
@@ -68,12 +43,6 @@ def test_update_opentelemetry_status_success(
self.assertIsNotNone(otel_manager.get_context_api())
self.assertIsNotNone(otel_manager.get_trace_context_propagator())
- def test_configure_opentelemetry_noops_when_not_initialized(self):
- otel_manager.set_context_api(None)
- otel_manager.set_trace_context_propagator(None)
-
- configure_opentelemetry(MagicMock())
-
@patch('builtins.__import__')
@patch("azure_functions_runtime.otel.update_opentelemetry_status")
def test_initialize_azure_monitor_success(
@@ -177,7 +146,7 @@ async def test_init_request_initialize_azure_monitor_disabled_app_setting(
self.assertNotIn("WorkerOpenTelemetryEnabled", capabilities)
@patch.dict(os.environ, {'PYTHON_ENABLE_OPENTELEMETRY': 'true'})
- def test_init_request_enable_opentelemetry_enabled_app_setting(
+ async def test_init_request_enable_opentelemetry_enabled_app_setting(
self,
):
worker_request = WorkerRequest(name='worker_init_request',
@@ -186,15 +155,13 @@ def test_init_request_enable_opentelemetry_enabled_app_setting(
FUNCTION_APP_DIRECTORY)),
properties={'host': '123',
'protos': protos})
- init_response = asyncio.run(worker_init_request(worker_request))
+ init_response = await worker_init_request(worker_request)
self.assertEqual(init_response.result.status,
protos.StatusResult.Success)
- # Verify OpenTelemetry propagation is initialized
- self.assertTrue(otel_manager.get_otel_libs_available())
- self.assertIsNotNone(otel_manager.get_context_api())
- self.assertIsNotNone(otel_manager.get_trace_context_propagator())
+ # Verify otel_libs_available is set to True
+ self.assertTrue(otel_manager.get_azure_monitor_available())
# Verify that WorkerOpenTelemetryEnabled capability is set to _TRUE
capabilities = init_response.capabilities
self.assertIn("WorkerOpenTelemetryEnabled", capabilities)
@@ -275,190 +242,3 @@ 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}"
- )
-
- @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.run_sync_func",
- return_value=None)
- @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_sync_function(
- self,
- mock_logger,
- mock_configure_otel,
- mock_functions,
- mock_get_context,
- mock_run_sync_func,
- mock_get_otel_libs,
- mock_get_azure_monitor,
- ):
- """Verify configure_opentelemetry is called before first log (sync function)."""
- mock_logger.info.side_effect = self._track_logger_info
- mock_configure_otel.side_effect = self._track_configure_otel
- mock_fi = self._make_mock_fi()
- mock_fi.is_async = False
- mock_functions.get_function.return_value = mock_fi
- invocation_context = MagicMock()
- mock_get_context.return_value = invocation_context
- request = self._make_mock_request()
-
- try:
- await invocation_request(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")
- mock_configure_otel.assert_called_once_with(invocation_context)
-
- 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}"
- )
diff --git a/workers/azure_functions_worker/dispatcher.py b/workers/azure_functions_worker/dispatcher.py
index b472bab50..fa8be1117 100644
--- a/workers/azure_functions_worker/dispatcher.py
+++ b/workers/azure_functions_worker/dispatcher.py
@@ -611,13 +611,6 @@ async def _handle__invocation_request(self, request):
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 = self._get_context(invoc_request, fi.name,
- fi.directory)
- if self._azure_monitor_available or self._otel_libs_available:
- self.configure_opentelemetry(fi_context)
-
function_invocation_logs: List[str] = [
'Received FunctionInvocationRequest',
f'request ID: {self.request_id}',
@@ -666,6 +659,9 @@ async def _handle__invocation_request(self, request):
await sync_http_request(http_request, func_http_request)
args[trigger_arg_name] = http_request
+ fi_context = self._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
@@ -680,6 +676,9 @@ async def _handle__invocation_request(self, request):
args[name] = bindings.Out()
if fi.is_async:
+ if self._azure_monitor_available or self._otel_libs_available:
+ self.configure_opentelemetry(fi_context)
+
call_result = \
await self._run_async_func(fi_context, fi.func, args)
else:
@@ -723,6 +722,7 @@ async def _handle__invocation_request(self, request):
# Actively flush customer print() function to console
sys.stdout.flush()
+
return protos.StreamingMessage(
request_id=self.request_id,
invocation_response=protos.InvocationResponse(
@@ -1014,6 +1014,8 @@ def _run_sync_func(self, invocation_id, context, func, params):
# invocation_id from ThreadPoolExecutor's threads.
context.thread_local_storage.invocation_id = invocation_id
try:
+ if self._azure_monitor_available or self._otel_libs_available:
+ self.configure_opentelemetry(context)
return ExtensionManager.get_sync_invocation_wrapper(context,
func)(params)
finally:
diff --git a/workers/pyproject.toml b/workers/pyproject.toml
index bcfc992ea..624d1a41d 100644
--- a/workers/pyproject.toml
+++ b/workers/pyproject.toml
@@ -28,7 +28,7 @@ classifiers = [
dependencies = [
"azure-functions==1.24.0; python_version < '3.10'",
"azure-functions==1.26.0b3; python_version >= '3.10' and python_version < '3.13'",
- "azure-functions==2.3.0b2; python_version >= '3.13'",
+ "azure-functions==2.2.0b5; python_version >= '3.13'",
"python-dateutil~=2.9.0",
"protobuf~=5.29.0; python_version <= '3.13'",
"protobuf~=6.33.1; python_version == '3.14'",
diff --git a/workers/tests/unittests/test_dispatcher.py b/workers/tests/unittests/test_dispatcher.py
index d501f3204..8b140a00e 100644
--- a/workers/tests/unittests/test_dispatcher.py
+++ b/workers/tests/unittests/test_dispatcher.py
@@ -2,14 +2,12 @@
# Licensed under the MIT License.
import asyncio
import collections as col
-import concurrent.futures
import contextvars
import os
import sys
-import threading
import unittest
from typing import Optional, Tuple
-from unittest.mock import MagicMock, patch
+from unittest.mock import patch
from tests.utils import testutils
from tests.utils.testutils import UNIT_TESTS_ROOT
@@ -633,55 +631,6 @@ async def test_dispatcher_functions_metadata_request_with_retry(self):
del sys.modules['function_app']
-class TestSyncInvocationContext(unittest.TestCase):
-
- def setUp(self):
- self.dispatcher = Dispatcher.__new__(Dispatcher)
- self.context = MagicMock()
- self.context.thread_local_storage = threading.local()
- self.executor = concurrent.futures.ThreadPoolExecutor(max_workers=1)
-
- def tearDown(self):
- self.executor.shutdown()
-
- @patch('azure_functions_worker.dispatcher.ExtensionManager'
- '.get_sync_invocation_wrapper')
- def test_invocation_id_cleared_after_success(self, mock_get_wrapper):
- observed_invocation_ids = []
- mock_get_wrapper.return_value = lambda params: (
- observed_invocation_ids.append(
- self.context.thread_local_storage.invocation_id))
-
- self.executor.submit(
- self.dispatcher._run_sync_func,
- 'test-invocation', self.context, MagicMock(), {}).result()
-
- remaining_invocation_id = self.executor.submit(
- lambda: self.context.thread_local_storage.invocation_id).result()
- self.assertEqual(observed_invocation_ids, ['test-invocation'])
- self.assertIsNone(remaining_invocation_id)
-
- @patch('azure_functions_worker.dispatcher.ExtensionManager'
- '.get_sync_invocation_wrapper')
- def test_invocation_id_cleared_after_exception(self, mock_get_wrapper):
- def invoke(params):
- self.assertEqual(
- self.context.thread_local_storage.invocation_id,
- 'test-invocation')
- raise RuntimeError('test error')
-
- mock_get_wrapper.return_value = invoke
-
- with self.assertRaisesRegex(RuntimeError, 'test error'):
- self.executor.submit(
- self.dispatcher._run_sync_func,
- 'test-invocation', self.context, MagicMock(), {}).result()
-
- remaining_invocation_id = self.executor.submit(
- lambda: self.context.thread_local_storage.invocation_id).result()
- self.assertIsNone(remaining_invocation_id)
-
-
class TestDispatcherSteinLegacyFallback(testutils.AsyncTestCase):
def setUp(self):
diff --git a/workers/tests/unittests/test_opentelemetry.py b/workers/tests/unittests/test_opentelemetry.py
index 35ab1746d..bdbedc874 100644
--- a/workers/tests/unittests/test_opentelemetry.py
+++ b/workers/tests/unittests/test_opentelemetry.py
@@ -8,7 +8,6 @@
from tests.utils import testutils
from azure_functions_worker import protos
-from azure_functions_worker.protos.FunctionRpc_pb2 import RpcTraceContext
class TestOpenTelemetry(unittest.TestCase):
@@ -218,282 +217,3 @@ def test_init_request_enable_azure_monitor_disabled_app_setting(
# Verify that WorkerOpenTelemetryEnabled capability is not set
capabilities = init_response.worker_init_response.capabilities
self.assertNotIn("WorkerOpenTelemetryEnabled", capabilities)
-
-
-class TestOpenTelemetryContextPropagation(unittest.TestCase):
- """Tests to verify OpenTelemetry context is propagated before logging.
-
- Issue #1626: OpenTelemetry context must be configured before the first
- log is emitted in _handle__invocation_request to ensure all logs have
- proper Operation Id in Application Insights.
- """
-
- def setUp(self):
- # Import directly from azure_functions_worker so this test always tests
- # the correct dispatcher regardless of the Python version (testutils
- # redirects to proxy_worker on Python >= 3.13).
- from azure_functions_worker.dispatcher import (
- ContextEnabledTask,
- Dispatcher,
- )
- self.loop = asyncio.new_event_loop()
- asyncio.set_event_loop(self.loop)
- # Use ContextEnabledTask factory so dispatcher's assertion passes
- self.loop.set_task_factory(
- lambda loop, coro, context=None: ContextEnabledTask(
- coro, loop=loop, context=context))
- self.dispatcher = Dispatcher(
- self.loop, '127.0.0.1', 0,
- 'test_worker_id', 'test_request_id',
- 1.0, 1000)
- self.call_order = []
-
- def tearDown(self):
- self.loop.close()
-
- def _track_configure_otel(self, *args, **kwargs):
- """Track when configure_opentelemetry is called."""
- self.call_order.append('configure_opentelemetry')
-
- def _track_logger_info(self, *args, **kwargs):
- """Track when logger.info is called."""
- self.call_order.append('logger_info')
-
- @patch.dict(os.environ, {'PYTHON_ENABLE_OPENTELEMETRY': 'true'})
- @patch('azure_functions_worker.dispatcher.logger')
- def test_otel_configured_before_first_log_in_invocation_request(
- self,
- mock_logger,
- ):
- """Verify configure_opentelemetry is called before the first log.
-
- This test ensures that when OpenTelemetry is enabled, the context
- is propagated before any logging occurs, so all logs have proper
- trace context (Operation Id).
- """
- # Set up tracking for call order
- mock_logger.info.side_effect = self._track_logger_info
-
- # Enable OpenTelemetry on the dispatcher
- self.dispatcher._otel_libs_available = True
- self.dispatcher._azure_monitor_available = False
-
- # Mock configure_opentelemetry to track when it's called
- self.dispatcher.configure_opentelemetry = MagicMock(
- side_effect=self._track_configure_otel
- )
-
- # Mock _get_context to return a valid context
- mock_context = MagicMock()
- mock_context.trace_context = MagicMock()
- mock_context.trace_context.trace_parent = "00-trace-parent"
- mock_context.trace_context.trace_state = "state"
- mock_context.thread_local_storage = MagicMock()
- self.dispatcher._get_context = MagicMock(return_value=mock_context)
-
- # Mock the functions registry
- 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.settlement_client_arg = None
- mock_fi.func = MagicMock(return_value=None)
- self.dispatcher._functions = MagicMock()
- self.dispatcher._functions.get_function = MagicMock(return_value=mock_fi)
-
- # Create a mock invocation request
- invoc_request = protos.StreamingMessage(
- invocation_request=protos.InvocationRequest(
- invocation_id="test-inv-123",
- function_id="test-func-id",
- trace_context=RpcTraceContext(
- trace_parent="00-trace-parent",
- trace_state="state"
- )
- )
- )
-
- # Mock _run_async_func to return None
- async def _noop():
- return None
- self.dispatcher._run_async_func = MagicMock(return_value=_noop())
-
- # Run the invocation request (will fail but we only care about call order)
- try:
- self.loop.run_until_complete(
- self.dispatcher._handle__invocation_request(invoc_request))
- except Exception:
- # We expect this may fail due to incomplete mocking,
- # but we only care about verifying call order
- pass
-
- # Assert both events were observed
- 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")
-
- # Assert configure_opentelemetry was called before the first logger.info
- 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.dict(os.environ, {'PYTHON_APPLICATIONINSIGHTS_ENABLE_TELEMETRY': 'true'})
- @patch('azure_functions_worker.dispatcher.logger')
- def test_azure_monitor_configured_before_first_log(
- self,
- mock_logger,
- ):
- """Verify OTel is configured before the first Azure Monitor log."""
- # Set up tracking for call order
- mock_logger.info.side_effect = self._track_logger_info
-
- # Enable Azure Monitor on the dispatcher
- self.dispatcher._otel_libs_available = False
- self.dispatcher._azure_monitor_available = True
-
- # Mock configure_opentelemetry to track when it's called
- self.dispatcher.configure_opentelemetry = MagicMock(
- side_effect=self._track_configure_otel
- )
-
- # Mock _get_context to return a valid context
- mock_context = MagicMock()
- mock_context.trace_context = MagicMock()
- mock_context.trace_context.trace_parent = "00-trace-parent"
- mock_context.trace_context.trace_state = "state"
- mock_context.thread_local_storage = MagicMock()
- self.dispatcher._get_context = MagicMock(return_value=mock_context)
-
- # Mock the functions registry
- 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.settlement_client_arg = None
- mock_fi.func = MagicMock(return_value=None)
- self.dispatcher._functions = MagicMock()
- self.dispatcher._functions.get_function = MagicMock(return_value=mock_fi)
-
- # Create a mock invocation request
- invoc_request = protos.StreamingMessage(
- invocation_request=protos.InvocationRequest(
- invocation_id="test-inv-456",
- function_id="test-func-id",
- trace_context=RpcTraceContext(
- trace_parent="00-trace-parent",
- trace_state="state"
- )
- )
- )
-
- # Mock _run_async_func to return None
- async def _noop():
- return None
- self.dispatcher._run_async_func = MagicMock(return_value=_noop())
-
- # Run the invocation request
- try:
- self.loop.run_until_complete(
- self.dispatcher._handle__invocation_request(invoc_request))
- except Exception:
- pass
-
- # Assert both events were observed
- 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")
-
- # Assert configure_opentelemetry was called before the first logger.info
- 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 should be called before first log. "
- f"Call order: {self.call_order}"
- )
-
- @patch.dict(os.environ, {'PYTHON_ENABLE_OPENTELEMETRY': 'true'})
- @patch('azure_functions_worker.dispatcher.logger')
- def test_otel_configured_before_first_log_sync_function(
- self,
- mock_logger,
- ):
- """Verify OTel is configured before the first sync function log."""
- mock_logger.info.side_effect = self._track_logger_info
-
- self.dispatcher._otel_libs_available = True
- self.dispatcher._azure_monitor_available = False
-
- self.dispatcher.configure_opentelemetry = MagicMock(
- side_effect=self._track_configure_otel
- )
-
- mock_context = MagicMock()
- mock_context.trace_context = MagicMock()
- mock_context.trace_context.trace_parent = "00-trace-parent"
- mock_context.trace_context.trace_state = "state"
- mock_context.thread_local_storage = MagicMock()
- self.dispatcher._get_context = MagicMock(return_value=mock_context)
-
- mock_fi = MagicMock()
- mock_fi.name = "test_function"
- mock_fi.is_async = False
- 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.settlement_client_arg = None
- mock_fi.func = MagicMock(return_value=None)
- self.dispatcher._functions = MagicMock()
- self.dispatcher._functions.get_function = MagicMock(return_value=mock_fi)
-
- invoc_request = protos.StreamingMessage(
- invocation_request=protos.InvocationRequest(
- invocation_id="test-inv-sync",
- function_id="test-func-id",
- trace_context=RpcTraceContext(
- trace_parent="00-trace-parent",
- trace_state="state"
- )
- )
- )
-
- self.dispatcher._run_sync_func = MagicMock(return_value=None)
-
- try:
- self.loop.run_until_complete(
- self.dispatcher._handle__invocation_request(invoc_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")
- self.dispatcher.configure_opentelemetry.assert_called_once_with(
- mock_context)
-
- 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}"
- )