fix(api): prevent identity logging deadlock (#39449)

api/controllers/web/wraps.py

@@ -11,6 +11,7 @@ from werkzeug.exceptions import BadRequest, NotFound, Unauthorized
 
 from constants import HEADER_NAME_APP_CODE
 from controllers.web.error import WebAppAuthAccessDeniedError, WebAppAuthRequiredError
+from core.logging.context import set_identity_context
 from extensions.ext_database import db
 from libs.passport import PassportService
 from libs.token import extract_webapp_passport
@@ -28,6 +29,11 @@ def validate_jwt_token[**P, R](
         @wraps(view)
         def decorated(*args: P.args, **kwargs: P.kwargs) -> R:
             app_model, end_user = decode_jwt_token()
+            set_identity_context(
+                tenant_id=end_user.tenant_id,
+                user_id=end_user.id,
+                user_type=end_user.type or "end_user",
+            )
             return view(app_model, end_user, *args, **kwargs)
 
         return decorated

api/core/logging/context.py

@@ -6,9 +6,21 @@ using Python's contextvars for thread-safe and async-safe storage.
 
 import uuid
 from contextvars import ContextVar
+from typing import NamedTuple
+
+
+class IdentityContext(NamedTuple):
+    """Immutable identity values captured for logging."""
+
+    tenant_id: str
+    user_id: str
+    user_type: str
+
 
 _request_id: ContextVar[str] = ContextVar("log_request_id", default="")
 _trace_id: ContextVar[str] = ContextVar("log_trace_id", default="")
+_EMPTY_IDENTITY_CONTEXT = IdentityContext(tenant_id="", user_id="", user_type="")
+_identity: ContextVar[IdentityContext] = ContextVar("log_identity", default=_EMPTY_IDENTITY_CONTEXT)
 
 
 def get_request_id() -> str:
@@ -21,15 +33,35 @@ def get_trace_id() -> str:
     return _trace_id.get()
 
 
+def get_identity_context() -> IdentityContext:
+    """Get the immutable tenant, user, and user-type snapshot for logging."""
+    return _identity.get()
+
+
+def set_identity_context(
+    *, tenant_id: str | None = None, user_id: str | None = None, user_type: str | None = None
+) -> None:
+    """Set primitive identity values already resolved by an authentication boundary."""
+    _identity.set(
+        IdentityContext(
+            tenant_id=tenant_id or "",
+            user_id=user_id or "",
+            user_type=user_type or "",
+        )
+    )
+
+
 def init_request_context() -> None:
-    """Initialize request context. Call at start of each request."""
+    """Initialize request context and discard identity left by earlier work."""
     req_id = uuid.uuid4().hex[:10]
     trace_id = uuid.uuid5(uuid.NAMESPACE_DNS, req_id).hex
     _request_id.set(req_id)
     _trace_id.set(trace_id)
+    _identity.set(_EMPTY_IDENTITY_CONTEXT)
 
 
 def clear_request_context() -> None:
-    """Clear request context. Call at end of request (optional)."""
+    """Clear request context at a request or task lifecycle boundary."""
     _request_id.set("")
     _trace_id.set("")
+    _identity.set(_EMPTY_IDENTITY_CONTEXT)

api/core/logging/filters.py

@@ -4,10 +4,7 @@ import contextlib
 import logging
 from typing import override
 
-import flask
-
-from core.logging.context import get_request_id, get_trace_id
-from core.logging.structured_formatter import IdentityDict
+from core.logging.context import get_identity_context, get_request_id, get_trace_id
 
 
 class TraceContextFilter(logging.Filter):
@@ -51,49 +48,16 @@ class TraceContextFilter(logging.Filter):
 
 
 class IdentityContextFilter(logging.Filter):
-    """
-    Filter that adds user identity context to log records.
-    Extracts tenant_id, user_id, and user_type from Flask-Login current_user.
+    """Add an identity snapshot without invoking authentication or database work.
+
+    Logging can run while other libraries hold internal locks, so this filter must
+    only read primitive ContextVar values populated by authentication boundaries.
     """
 
     @override
     def filter(self, record: logging.LogRecord) -> bool:
-        identity = self._extract_identity()
-        record.tenant_id = identity.get("tenant_id", "")
-        record.user_id = identity.get("user_id", "")
-        record.user_type = identity.get("user_type", "")
+        identity = get_identity_context()
+        record.tenant_id = identity.tenant_id
+        record.user_id = identity.user_id
+        record.user_type = identity.user_type
         return True
-
-    def _extract_identity(self) -> IdentityDict:
-        """Extract identity from current_user if in request context."""
-        try:
-            if not flask.has_request_context():
-                return {}
-            from flask_login import current_user
-
-            # Check if user is authenticated using the proxy
-            if not current_user.is_authenticated:
-                return {}
-
-            # Access the underlying user object
-            user = current_user
-
-            from models import Account
-            from models.model import EndUser
-
-            identity: IdentityDict = {}
-
-            match user:
-                case Account():
-                    if user.current_tenant_id:
-                        identity["tenant_id"] = user.current_tenant_id
-                    identity["user_id"] = user.id
-                    identity["user_type"] = "account"
-                case EndUser():
-                    identity["tenant_id"] = user.tenant_id
-                    identity["user_id"] = user.id
-                    identity["user_type"] = user.type or "end_user"
-
-            return identity
-        except Exception:
-            return {}

api/extensions/ext_login.py

@@ -1,5 +1,6 @@
 import json
-from typing import cast, override
+import logging
+from typing import assert_never, cast, override
 
 import flask_login
 from flask import Request, Response, request
@@ -11,6 +12,7 @@ from werkzeug.exceptions import NotFound, Unauthorized
 from configs import dify_config
 from constants import HEADER_NAME_APP_CODE
 from core.db.session_factory import session_factory
+from core.logging.context import set_identity_context
 from dify_app import DifyApp
 from libs.passport import PassportService
 from libs.token import extract_access_token, extract_console_cookie_token, extract_webapp_passport
@@ -19,6 +21,8 @@ from models.enums import EndUserType
 from models.model import AppMCPServer, EndUser
 from services.account_service import AccountService
 
+logger = logging.getLogger(__name__)
+
 type LoginUser = Account | EndUser
 
 
@@ -156,13 +160,24 @@ def _load_user_from_request(request_from_flask_login: Request, session: Session)
 @user_logged_in.connect
 @user_loaded_from_request.connect
 def on_user_logged_in(_sender: object, user: LoginUser) -> None:
-    """Called when a user logged in.
+    """Snapshot authenticated identity into the side-effect-free logging context.
 
     Note: AccountService.load_logged_in_account will populate user.current_tenant_id
     through the load_user method, which calls account.set_tenant_id_with_session().
     """
-    # tenant_id context variable removed - using current_user.current_tenant_id directly
-    pass
+    set_identity_context()
+    try:
+        match user:
+            case Account():
+                set_identity_context(tenant_id=user.current_tenant_id, user_id=user.id, user_type="account")
+            case EndUser():
+                set_identity_context(tenant_id=user.tenant_id, user_id=user.id, user_type=user.type or "end_user")
+            case _ as unreachable:
+                assert_never(unreachable)
+    except Exception:
+        # Logging enrichment must never make authentication fail.
+        logger.exception("Failed to set logging identity context")
+        return
 
 
 @login_manager.unauthorized_handler

api/extensions/otel/runtime.py

@@ -69,12 +69,17 @@ def on_user_loaded(_sender, user: Union["Account", "EndUser"]):
         if user:
             try:
                 current_span = get_current_span()
+                if not current_span.is_recording():
+                    return
                 tenant_id = extract_tenant_id(user)
                 if not tenant_id:
                     return
-                if current_span:
-                    current_span.set_attribute(DifySpanAttributes.TENANT_ID, tenant_id)
-                    current_span.set_attribute(GenAIAttributes.USER_ID, user.id)
+                current_span.set_attributes(
+                    {
+                        DifySpanAttributes.TENANT_ID: tenant_id,
+                        GenAIAttributes.USER_ID: user.id,
+                    }
+                )
             except Exception:
                 logger.exception("Error setting tenant and user attributes")
                 pass

api/tests/unit_tests/controllers/web/test_wraps.py

@@ -0,0 +1,49 @@
+from unittest import mock
+
+import pytest
+from werkzeug.exceptions import Unauthorized
+
+from core.logging.context import clear_request_context, get_identity_context
+
+
+@pytest.fixture(autouse=True)
+def _reset_logging_context():
+    clear_request_context()
+    yield
+    clear_request_context()
+
+
+def test_validate_jwt_token_sets_logging_identity_before_view() -> None:
+    from controllers.web import wraps
+
+    app_model = mock.Mock()
+    end_user = mock.Mock(id="end-user-id", tenant_id="tenant-id", type=None)
+    clear_request_context()
+
+    @wraps.validate_jwt_token
+    def protected_view(received_app, received_user):
+        assert get_identity_context() == ("tenant-id", "end-user-id", "end_user")
+        return received_app, received_user
+
+    with mock.patch.object(wraps, "decode_jwt_token", return_value=(app_model, end_user)):
+        result = protected_view()
+
+    assert result == (app_model, end_user)
+
+
+def test_validate_jwt_token_does_not_set_identity_when_authentication_fails() -> None:
+    from controllers.web import wraps
+
+    clear_request_context()
+
+    @wraps.validate_jwt_token
+    def protected_view(_app, _user):
+        raise AssertionError("view must not be called")
+
+    with (
+        mock.patch.object(wraps, "decode_jwt_token", side_effect=Unauthorized()),
+        pytest.raises(Unauthorized),
+    ):
+        protected_view()
+
+    assert get_identity_context() == ("", "", "")

api/tests/unit_tests/core/logging/test_context.py

@@ -1,15 +1,27 @@
 """Tests for logging context module."""
 
 import uuid
+from contextvars import copy_context
+
+import pytest
 
 from core.logging.context import (
     clear_request_context,
+    get_identity_context,
     get_request_id,
     get_trace_id,
     init_request_context,
+    set_identity_context,
 )
 
 
+@pytest.fixture(autouse=True)
+def _reset_logging_context():
+    clear_request_context()
+    yield
+    clear_request_context()
+
+
 class TestLoggingContext:
     """Tests for the logging context functions."""
 
@@ -77,3 +89,41 @@ class TestLoggingContext:
 
         # IDs should be different
         assert id1 != id2
+
+    def test_set_identity_context(self):
+        set_identity_context(tenant_id="tenant-1", user_id="user-1", user_type="end_user")
+
+        identity = get_identity_context()
+        assert identity.tenant_id == "tenant-1"
+        assert identity.user_id == "user-1"
+        assert identity.user_type == "end_user"
+
+    def test_set_identity_context_replaces_all_fields(self):
+        set_identity_context(tenant_id="tenant-1", user_id="user-1", user_type="account")
+
+        set_identity_context(user_id="user-2", user_type="end_user")
+
+        assert get_identity_context() == ("", "user-2", "end_user")
+
+    def test_identity_context_is_copied_as_primitive_values(self):
+        set_identity_context(tenant_id="tenant-1", user_id="user-1", user_type="end_user")
+        copied_context = copy_context()
+
+        clear_request_context()
+
+        assert get_identity_context() == ("", "", "")
+        assert copied_context.run(get_identity_context) == ("tenant-1", "user-1", "end_user")
+
+    def test_init_clears_existing_identity_context(self):
+        set_identity_context(tenant_id="tenant-1", user_id="user-1", user_type="end_user")
+
+        init_request_context()
+
+        assert get_identity_context() == ("", "", "")
+
+    def test_clear_resets_identity_context(self):
+        set_identity_context(tenant_id="tenant-1", user_id="user-1", user_type="end_user")
+
+        clear_request_context()
+
+        assert get_identity_context() == ("", "", "")

api/tests/unit_tests/core/logging/test_filters.py

@@ -1,5 +1,6 @@
 """Tests for logging filters."""
 
+import io
 import logging
 from unittest import mock
 
@@ -19,6 +20,15 @@ def log_record():
     )
 
 
+@pytest.fixture(autouse=True)
+def _reset_logging_context():
+    from core.logging.context import clear_request_context
+
+    clear_request_context()
+    yield
+    clear_request_context()
+
+
 class TestTraceContextFilter:
     def test_sets_empty_trace_id_without_context(self, log_record):
         from core.logging.context import clear_request_context
@@ -147,8 +157,10 @@ class TestTraceContextFilter:
 
 class TestIdentityContextFilter:
     def test_sets_empty_identity_without_request_context(self, log_record):
+        from core.logging.context import clear_request_context
         from core.logging.filters import IdentityContextFilter
 
+        clear_request_context()
         filter = IdentityContextFilter()
         result = filter.filter(log_record)
 
@@ -164,131 +176,92 @@ class TestIdentityContextFilter:
         result = filter.filter(log_record)
         assert result is True
 
-    def test_handles_exception_gracefully(self, log_record):
+    def test_uses_explicit_identity_context_without_flask_context(self, log_record):
+        from core.logging.context import set_identity_context
         from core.logging.filters import IdentityContextFilter
 
+        set_identity_context(tenant_id="tenant_id", user_id="end_user_id", user_type="end_user")
+
         filter = IdentityContextFilter()
+        filter.filter(log_record)
 
-        # Should not raise even if something goes wrong
-        with mock.patch(
-            "core.logging.filters.flask.has_request_context", side_effect=Exception("Test error"), autospec=True
-        ):
-            result = filter.filter(log_record)
-            assert result is True
-            assert log_record.tenant_id == ""
+        assert log_record.tenant_id == "tenant_id"
+        assert log_record.user_id == "end_user_id"
+        assert log_record.user_type == "end_user"
 
-    def test_sets_empty_identity_unauthenticated(self, log_record):
+    def test_does_not_trigger_flask_login_request_loader(self, log_record):
+        from flask import Flask
+        from flask_login import LoginManager
+
+        from core.logging.context import clear_request_context
         from core.logging.filters import IdentityContextFilter
 
-        mock_user = mock.MagicMock()
-        mock_user.is_authenticated = False
+        app = Flask(__name__)
+        app.secret_key = "test"
+        login_manager = LoginManager(app)
+        request_loader = mock.Mock(return_value=None)
+        login_manager.request_loader(request_loader)
+        clear_request_context()
 
-        with (
-            mock.patch("flask.has_request_context", return_value=True),
-            mock.patch("flask_login.current_user", mock_user),
-        ):
-            filter = IdentityContextFilter()
-            filter.filter(log_record)
-            assert log_record.user_id == ""
+        with app.test_request_context("/"):
+            from flask import g
 
-    def test_sets_identity_for_account(self, log_record):
+            assert "_login_user" not in g
+            IdentityContextFilter().filter(log_record)
+            assert "_login_user" not in g
+
+        request_loader.assert_not_called()
+        assert log_record.tenant_id == ""
+        assert log_record.user_id == ""
+        assert log_record.user_type == ""
+
+    def test_ended_otel_span_warning_does_not_trigger_request_loader(self):
+        from flask import Flask, g
+        from flask_login import LoginManager
+        from opentelemetry import trace
+        from opentelemetry.sdk.trace import TracerProvider
+
+        from core.logging.context import clear_request_context
         from core.logging.filters import IdentityContextFilter
 
-        class MockAccount:
-            pass
+        app = Flask(__name__)
+        app.secret_key = "test"
+        login_manager = LoginManager(app)
+        request_loader = mock.Mock(return_value=None)
+        login_manager.request_loader(request_loader)
 
-        mock_user = MockAccount()
-        mock_user.id = "account_id"
-        mock_user.current_tenant_id = "tenant_id"
-        mock_user.is_authenticated = True
+        span = TracerProvider().get_tracer(__name__).start_span("ended")
+        span.end()
 
-        with (
-            mock.patch("flask.has_request_context", return_value=True),
-            mock.patch("models.Account", MockAccount),
-            mock.patch("flask_login.current_user", mock_user),
-        ):
-            filter = IdentityContextFilter()
-            filter.filter(log_record)
+        stream = io.StringIO()
+        handler = logging.StreamHandler(stream)
+        handler.addFilter(IdentityContextFilter())
+        handler.setFormatter(logging.Formatter("%(tenant_id)s %(user_id)s %(user_type)s %(message)s"))
 
-            assert log_record.tenant_id == "tenant_id"
-            assert log_record.user_id == "account_id"
-            assert log_record.user_type == "account"
+        sdk_logger = logging.getLogger("opentelemetry.sdk.trace")
+        previous_level = sdk_logger.level
+        previous_propagate = sdk_logger.propagate
+        previous_disabled = sdk_logger.disabled
+        sdk_logger.addHandler(handler)
+        sdk_logger.setLevel(logging.WARNING)
+        sdk_logger.propagate = False
+        sdk_logger.disabled = False
+        clear_request_context()
 
-    def test_sets_identity_for_account_no_tenant(self, log_record):
-        from core.logging.filters import IdentityContextFilter
+        try:
+            with app.test_request_context("/"), trace.use_span(span, end_on_exit=False):
+                assert "_login_user" not in g
 
-        class MockAccount:
-            pass
+                span.set_attribute("test.key", "test-value")
 
-        mock_user = MockAccount()
-        mock_user.id = "account_id"
-        mock_user.current_tenant_id = None
-        mock_user.is_authenticated = True
+                assert "_login_user" not in g
+        finally:
+            clear_request_context()
+            sdk_logger.removeHandler(handler)
+            sdk_logger.setLevel(previous_level)
+            sdk_logger.propagate = previous_propagate
+            sdk_logger.disabled = previous_disabled
+            handler.close()
 
-        with (
-            mock.patch("flask.has_request_context", return_value=True),
-            mock.patch("models.Account", MockAccount),
-            mock.patch("flask_login.current_user", mock_user),
-        ):
-            filter = IdentityContextFilter()
-            filter.filter(log_record)
-
-            assert log_record.tenant_id == ""
-            assert log_record.user_id == "account_id"
-            assert log_record.user_type == "account"
-
-    def test_sets_identity_for_end_user(self, log_record):
-        from core.logging.filters import IdentityContextFilter
-
-        class MockEndUser:
-            pass
-
-        class AnotherClass:
-            pass
-
-        mock_user = MockEndUser()
-        mock_user.id = "end_user_id"
-        mock_user.tenant_id = "tenant_id"
-        mock_user.type = "custom_type"
-        mock_user.is_authenticated = True
-
-        with (
-            mock.patch("flask.has_request_context", return_value=True),
-            mock.patch("models.model.EndUser", MockEndUser),
-            mock.patch("models.Account", AnotherClass),
-            mock.patch("flask_login.current_user", mock_user),
-        ):
-            filter = IdentityContextFilter()
-            filter.filter(log_record)
-
-            assert log_record.tenant_id == "tenant_id"
-            assert log_record.user_id == "end_user_id"
-            assert log_record.user_type == "custom_type"
-
-    def test_sets_identity_for_end_user_default_type(self, log_record):
-        from core.logging.filters import IdentityContextFilter
-
-        class MockEndUser:
-            pass
-
-        class AnotherClass:
-            pass
-
-        mock_user = MockEndUser()
-        mock_user.id = "end_user_id"
-        mock_user.tenant_id = "tenant_id"
-        mock_user.type = None
-        mock_user.is_authenticated = True
-
-        with (
-            mock.patch("flask.has_request_context", return_value=True),
-            mock.patch("models.model.EndUser", MockEndUser),
-            mock.patch("models.Account", AnotherClass),
-            mock.patch("flask_login.current_user", mock_user),
-        ):
-            filter = IdentityContextFilter()
-            filter.filter(log_record)
-
-            assert log_record.tenant_id == "tenant_id"
-            assert log_record.user_id == "end_user_id"
-            assert log_record.user_type == "end_user"
+        request_loader.assert_not_called()
+        assert "Setting attribute on ended span" in stream.getvalue()

api/tests/unit_tests/extensions/otel/test_runtime.py

@@ -0,0 +1,75 @@
+from unittest import mock
+
+import pytest
+from opentelemetry import trace
+from opentelemetry.sdk.trace import TracerProvider
+
+from core.logging.context import clear_request_context
+
+
+@pytest.fixture(autouse=True)
+def _reset_logging_context():
+    clear_request_context()
+    yield
+    clear_request_context()
+
+
+def test_on_user_loaded_does_not_write_to_non_recording_span() -> None:
+    from extensions.otel import runtime
+
+    span = mock.MagicMock()
+    span.is_recording.return_value = False
+    user = mock.Mock(id="user-id")
+
+    with (
+        mock.patch.object(runtime.dify_config, "ENABLE_OTEL", True),
+        mock.patch("opentelemetry.trace.get_current_span", return_value=span),
+        mock.patch.object(runtime, "extract_tenant_id", return_value="tenant-id"),
+    ):
+        runtime.on_user_loaded(None, user)
+
+    span.is_recording.assert_called_once_with()
+    span.set_attribute.assert_not_called()
+    span.set_attributes.assert_not_called()
+
+
+def test_on_user_loaded_sets_attributes_on_recording_span() -> None:
+    from extensions.otel import runtime
+    from extensions.otel.semconv import DifySpanAttributes, GenAIAttributes
+
+    span = mock.MagicMock()
+    span.is_recording.return_value = True
+    user = mock.Mock(id="user-id")
+
+    with (
+        mock.patch.object(runtime.dify_config, "ENABLE_OTEL", True),
+        mock.patch("opentelemetry.trace.get_current_span", return_value=span),
+        mock.patch.object(runtime, "extract_tenant_id", return_value="tenant-id"),
+    ):
+        runtime.on_user_loaded(None, user)
+
+    span.set_attributes.assert_called_once_with(
+        {
+            DifySpanAttributes.TENANT_ID: "tenant-id",
+            GenAIAttributes.USER_ID: "user-id",
+        }
+    )
+
+
+def test_on_user_loaded_ignores_ended_sdk_span(caplog) -> None:
+    from extensions.otel import runtime
+
+    tracer_provider = TracerProvider()
+    span = tracer_provider.get_tracer(__name__).start_span("ended")
+    span.end()
+    user = mock.Mock(id="user-id")
+
+    with (
+        trace.use_span(span, end_on_exit=False),
+        mock.patch.object(runtime.dify_config, "ENABLE_OTEL", True),
+        mock.patch.object(runtime, "extract_tenant_id", return_value="tenant-id"),
+        caplog.at_level("WARNING", logger="opentelemetry.sdk.trace"),
+    ):
+        runtime.on_user_loaded(None, user)
+
+    assert "Setting attribute on ended span" not in caplog.text

api/tests/unit_tests/extensions/test_ext_login.py

@@ -1,10 +1,22 @@
 import json
+from typing import cast
+from unittest import mock
 
+import pytest
 from flask import Response
 
+from core.logging.context import clear_request_context, get_identity_context
+from extensions import ext_login
 from extensions.ext_login import unauthorized_handler
 
 
+@pytest.fixture(autouse=True)
+def _reset_logging_context():
+    clear_request_context()
+    yield
+    clear_request_context()
+
+
 def test_unauthorized_handler_returns_json_response() -> None:
     response = unauthorized_handler()
 
@@ -15,3 +27,50 @@ def test_unauthorized_handler_returns_json_response() -> None:
         "code": "unauthorized",
         "message": "Unauthorized.",
     }
+
+
+def test_on_user_logged_in_sets_account_logging_identity() -> None:
+    account = mock.Mock(spec=ext_login.Account)
+    account.id = "account-id"
+    account.current_tenant_id = "tenant-id"
+    clear_request_context()
+
+    ext_login.on_user_logged_in(None, account)
+
+    assert get_identity_context() == ("tenant-id", "account-id", "account")
+
+
+def test_on_user_logged_in_sets_end_user_logging_identity() -> None:
+    end_user = mock.Mock(spec=ext_login.EndUser)
+    end_user.id = "end-user-id"
+    end_user.tenant_id = "tenant-id"
+    end_user.type = "browser"
+    clear_request_context()
+
+    ext_login.on_user_logged_in(None, end_user)
+
+    assert get_identity_context() == ("tenant-id", "end-user-id", "browser")
+
+
+def test_on_user_logged_in_does_not_break_auth_when_identity_is_unavailable() -> None:
+    account = mock.Mock(spec=ext_login.Account)
+    type(account).current_tenant_id = mock.PropertyMock(side_effect=RuntimeError("unavailable"))
+    account.id = "account-id"
+    clear_request_context()
+
+    with mock.patch.object(ext_login.logger, "exception") as logger_exception:
+        ext_login.on_user_logged_in(None, account)
+
+    assert get_identity_context() == ("", "", "")
+    logger_exception.assert_called_once_with("Failed to set logging identity context")
+
+
+def test_on_user_logged_in_logs_unsupported_user_type() -> None:
+    unsupported_user = cast(ext_login.LoginUser, object())
+    clear_request_context()
+
+    with mock.patch.object(ext_login.logger, "exception") as logger_exception:
+        ext_login.on_user_logged_in(None, unsupported_user)
+
+    assert get_identity_context() == ("", "", "")
+    logger_exception.assert_called_once_with("Failed to set logging identity context")