Skip to content

fix: early OpenTelemetry context propagation in invocation#1882

Draft
hallvictoria wants to merge 3 commits into
devfrom
hallvictoria/otel-context-prop
Draft

fix: early OpenTelemetry context propagation in invocation#1882
hallvictoria wants to merge 3 commits into
devfrom
hallvictoria/otel-context-prop

Conversation

@hallvictoria

Copy link
Copy Markdown
Contributor

Description

Fixes #1626


Move OpenTelemetry context propagation earlier in _handle__invocation_request to ensure all logs have proper trace context (Operation Id) in Application Insights.

Problem: When OpenTelemetry is enabled, the first log emitted in _handle__invocation_request had a blank Operation Id because configure_opentelemetry() was called after the first log was emitted.

Solution: Move fi_context initialization and configure_opentelemetry() call to immediately after FunctionInfo is retrieved, before any logging occurs.

Pull Request Checklist

Host-Worker Contract

  • Does this PR impact the host-worker contract (e.g., gRPC messages, shared interfaces)?
    • If yes, have the changes been applied to:
      • azure_functions_worker (Python <= 3.12)
      • proxy_worker (Python >= 3.13)
    • If no, please explain why: This PR only changes the order of operations within the invocation request handler. No gRPC messages or shared interfaces are modified.

Worker Execution Logic

  • Does this PR affect worker execution logic (e.g., function invocation, bindings, lifecycle)?
    If yes, please answer the following:

Python Version Coverage

  • Does this change apply to both Python <=3.12 and 3.13+?
  • If yes, have the changes been made to:
    • azure_functions_worker (Python <= 3.12)
    • runtimes/v1 / runtimes/v2 (Python >= 3.13)
  • If no, please explain why:

Programming Model Compatibility (for Python 3.13+)

  • Does this change apply to both:
    • V1 programming model (runtimes/v1)?
    • V2 programming model (runtimes/v2)?
  • Explanation (if limited to one model): Change applies to both models as both have the same late context propagation issue.

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR addresses late OpenTelemetry context propagation during function invocation handling so that invocation logs are correlated with the proper trace context (Operation Id) in Application Insights.

Changes:

  • Move OpenTelemetry context initialization/configuration earlier in the invocation request handlers (worker dispatcher + v1/v2 runtimes).
  • Remove the later (async-only) OpenTelemetry configuration points after args/bindings setup.
  • Add a unit test intended to validate that OpenTelemetry is configured before the first invocation log in the worker dispatcher.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 8 comments.

File Description
workers/tests/unittests/test_opentelemetry.py Adds tests to validate OpenTelemetry context propagation occurs before the first invocation log.
workers/azure_functions_worker/dispatcher.py Moves _get_context + configure_opentelemetry() before the first logger.info in _handle__invocation_request.
runtimes/v2/azure_functions_runtime/handle_event.py Moves context creation + OpenTelemetry configuration before the first invocation logger.info.
runtimes/v1/azure_functions_runtime_v1/handle_event.py Moves context creation + OpenTelemetry configuration before the first invocation logger.info.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment on lines +160 to +165
# Initialize context and configure OpenTelemetry early
# to ensure all logs have proper trace context (Operation Id)
fi_context = get_context(invoc_request, fi.name,
fi.directory)
if otel_manager.get_azure_monitor_available():
configure_opentelemetry(fi_context)
Comment on lines +186 to +187
# Initialize context and configure OpenTelemetry early
# to ensure all logs have proper trace context (Operation Id)
Comment on lines +188 to +192
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)
Comment on lines +162 to +166
fi_context = get_context(invoc_request, fi.name,
fi.directory)
if otel_manager.get_azure_monitor_available():
configure_opentelemetry(fi_context)

Comment on lines +305 to +308
# Mock _run_async_func to return None
self.dispatcher._run_async_func = MagicMock(
return_value=asyncio.coroutine(lambda: None)()
)
Comment on lines +389 to +392
# Mock _run_async_func to return None
self.dispatcher._run_async_func = MagicMock(
return_value=asyncio.coroutine(lambda: None)()
)
Comment on lines +319 to +334
# Verify configure_opentelemetry was called
self.assertIn('configure_opentelemetry', self.call_order,
"configure_opentelemetry should have been called")

# Find the position of configure_opentelemetry and first logger.info
if 'configure_opentelemetry' in self.call_order and \
'logger_info' in self.call_order:
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}"
)
Comment on lines +401 to +411
# Verify configure_opentelemetry was called before first log
if 'configure_opentelemetry' in self.call_order and \
'logger_info' in self.call_order:
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}"
)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[Bug] Late OpenTelemetry context propagation in _handle__invocation_request

2 participants