fix(proxy): log configured model access denials at the final response boundary

Post-auth denials from can_key_call_resolved_model (per-request alias
rewrite, MCP sampling, realtime) never reach the auth exception handler,
so the internal allowlist reason was dropped when
model_access_denied_message was set. Log it once from the ProxyException
response handler and the realtime rejection path instead, and convert
JWT ModelAccessDeniedHTTPException into the specialized ProxyException so
the same boundary covers it

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>

litellm/proxy/auth/auth_exception_handler.py

@@ -53,6 +53,14 @@ def _as_proxy_exception(e: Exception) -> ProxyException:
             param=None,
             code=getattr(e, "status_code", status.HTTP_429_TOO_MANY_REQUESTS),
         )
+    if isinstance(e, ModelAccessDeniedHTTPException):
+        return ModelAccessDeniedProxyException(
+            message=str(e.detail),
+            internal_message=e.internal_message,
+            type=ProxyErrorTypes.auth_error,
+            param="None",
+            code=e.status_code,
+        )
     if isinstance(e, HTTPException):
         return ProxyException(
             message=getattr(e, "detail", f"Authentication Error({e})"),
@@ -77,14 +85,6 @@ def _as_proxy_exception(e: Exception) -> ProxyException:
     )
 
 
-def _model_access_denied_internal_message(e: Exception) -> str | None:
-    if not litellm.model_access_denied_message:
-        return None
-    if not isinstance(e, (ModelAccessDeniedProxyException, ModelAccessDeniedHTTPException)):
-        return None
-    return e.internal_message.replace("\r", "").replace("\n", "")
-
-
 def _get_user_agent(request: Request) -> str | None:
     if "headers" not in request.scope:
         return None
@@ -176,9 +176,6 @@ class UserAPIKeyAuthExceptionHandler:
             # survives a raising callback pipeline. Classify and route malformed virtual-key
             # rejections to WARNING on stdout (suppressible via LITELLM_LOG=ERROR).
             log_extra: Final = {"requester_ip": requester_ip}
-            denied_internal_message: Final = _model_access_denied_internal_message(e)
-            if denied_internal_message is not None:
-                verbose_proxy_logger.warning(denied_internal_message, extra=log_extra)
             is_invalid_virtual_key: Final = is_invalid_virtual_key_error(e)
             is_quiet_log: Final = is_invalid_virtual_key and not litellm.log_client_error_tracebacks
             logger: Final = verbose_proxy_stdout_logger if is_quiet_log else verbose_proxy_logger

litellm/proxy/proxy_server.py

@@ -106,6 +106,7 @@ from litellm.proxy._types import (
     LiteLLM_TeamTableCachedObj,
     LiteLLM_UserTable,
     LitellmUserRoles,
+    ModelAccessDeniedProxyException,
     PassThroughGenericEndpoint,
     ProxyErrorTypes,
     ProxyException,
@@ -1668,6 +1669,7 @@ class UserAPIKeyCacheTTLEnum(enum.Enum):
 @app.exception_handler(ProxyException)
 async def openai_exception_handler(request: Request, exc: ProxyException):
     # NOTE: DO NOT MODIFY THIS, its crucial to map to Openai exceptions
+    _log_model_access_denial(exc)
     headers: Final = exc.headers
     error_dict: Final = exc.to_dict()
     status_code: Final = int(exc.code) if exc.code else status.HTTP_500_INTERNAL_SERVER_ERROR
@@ -1679,6 +1681,12 @@ async def openai_exception_handler(request: Request, exc: ProxyException):
     )
 
 
+def _log_model_access_denial(exc: ProxyException) -> None:
+    if not litellm.model_access_denied_message or not isinstance(exc, ModelAccessDeniedProxyException):
+        return
+    verbose_proxy_logger.warning(exc.internal_message.replace("\r", "").replace("\n", ""))
+
+
 def _close_dangling_otel_server_span(request: Request, status_code: int, exc: Exception | None = None) -> None:
     parent_otel_span: Final[_Span | None] = getattr(request.state, "parent_otel_span", None)
     if parent_otel_span is None:
@@ -11967,6 +11975,7 @@ async def realtime_websocket_endpoint(
             llm_router=llm_router,
         )
     except ProxyException as e:
+        _log_model_access_denial(e)
         await _reject_realtime_session(websocket, user_api_key_dict, code=1008, reason=e.message[:120])
         return
     await websocket.accept(**accept_kwargs)

tests/test_litellm/proxy/auth/test_auth_exception_handler.py

@@ -1022,7 +1022,9 @@ def _denied_jwt_exception() -> ModelAccessDeniedHTTPException:
         pytest.param(_denied_jwt_exception, id="jwt_http_exception"),
     ],
 )
-async def test_handle_authentication_error_logs_sanitized_model_access_denial_once(monkeypatch, make_denial, caplog):
+async def test_handle_authentication_error_keeps_internal_message_on_model_access_denial(
+    monkeypatch, make_denial, caplog
+):
     monkeypatch.setattr(litellm, "model_access_denied_message", _DENIED_MESSAGE_TEMPLATE)
     handler = UserAPIKeyAuthExceptionHandler()
     denial = make_denial()
@@ -1041,17 +1043,14 @@ async def test_handle_authentication_error_logs_sanitized_model_access_denial_on
             {"allow_requests_on_db_unavailable": False},
         ),
         caplog.at_level("WARNING", logger="LiteLLM Proxy"),
-        pytest.raises(ProxyException) as exc_info,
+        pytest.raises(ModelAccessDeniedProxyException) as exc_info,
     ):
         await handler._handle_authentication_error(denial, MagicMock(), {}, "/v1/chat/completions", None, "sk-bad-key")
 
     assert exc_info.value.code == str(status.HTTP_403_FORBIDDEN)
     assert "internal-models" not in str(exc_info.value.message)
-    denial_records = [r for r in caplog.records if "internal-models" in r.getMessage()]
-    assert len(denial_records) == 1
-    assert denial_records[0].levelname == "WARNING"
-    assert "\n" not in denial_records[0].getMessage()
-    assert "gpt-5.6WARNING forged log line" in denial_records[0].getMessage()
+    assert exc_info.value.internal_message == denial.internal_message
+    assert [r for r in caplog.records if r.levelname == "WARNING" and "internal-models" in r.getMessage()] == []
 
 
 @pytest.mark.asyncio

tests/test_litellm/proxy/test_proxy_server.py

@@ -19,7 +19,7 @@ import fastapi.routing
 import httpx
 import pytest
 import yaml
-from fastapi import FastAPI
+from fastapi import FastAPI, Request
 from fastapi.encoders import jsonable_encoder
 from fastapi.staticfiles import StaticFiles
 from fastapi.testclient import TestClient
@@ -31,10 +31,17 @@ from litellm.caching.caching import RedisCache
 from litellm.caching.redis_cluster_cache import RedisClusterCache
 from litellm.litellm_core_utils.get_model_cost_map import ModelCostMapReloaded
 from litellm.caching.dual_cache import DualCache
-from litellm.proxy._types import LitellmUserRoles, TokenCountRequest, UserAPIKeyAuth
+from litellm.proxy._types import (
+    LitellmUserRoles,
+    ModelAccessDeniedProxyException,
+    ProxyErrorTypes,
+    ProxyException,
+    TokenCountRequest,
+    UserAPIKeyAuth,
+)
 from litellm.proxy.auth.user_api_key_auth import user_api_key_auth
 from litellm.proxy.hooks.parallel_request_limiter_v3 import RequestRateLimiterStash
-from litellm.proxy.proxy_server import app, initialize
+from litellm.proxy.proxy_server import app, initialize, openai_exception_handler
 from litellm.utils import _invalidate_model_cost_lowercase_map
 
 example_embedding_result = {
@@ -10003,6 +10010,7 @@ async def _lit6973_drive_realtime_session(
     backend_logged_failure: bool = False,
     phase_one_exit: str | None = None,
     websocket: MagicMock | None = None,
+    model_access_exception: ProxyException | None = None,
 ) -> MagicMock:
     """Drive realtime_websocket_endpoint through one of its reservation-settling exits.
 
@@ -10035,10 +10043,10 @@ async def _lit6973_drive_realtime_session(
         if backend_logged_failure:
             logging_obj.model_call_details[REALTIME_SESSION_FAILURE_LOGGED_KEY] = True
 
-    from litellm.proxy._types import ProxyException
-
     model_access_error: Final = (
-        ProxyException(message="key cannot access model", type="auth_error", param="model", code=401)
+        model_access_exception
+        if model_access_exception is not None
+        else ProxyException(message="key cannot access model", type="auth_error", param="model", code=401)
         if phase_one_exit == "model_access"
         else None
     )
@@ -10916,6 +10924,95 @@ def test_validate_model_access_denied_message_empty_restores_detailed_default(em
     assert _validate_general_settings_ui_litellm_value("model_access_denied_message", empty_value) is None
 
 
+def _model_access_denied_proxy_exception():
+    return ModelAccessDeniedProxyException(
+        message="The model `gpt-5.6\r\nWARNING forged log line` is unavailable for this API key or does not exist.",
+        internal_message="key not allowed to access model. This key can only access models=['internal-models']. "
+        "Tried to access gpt-5.6\r\nWARNING forged log line",
+        type=ProxyErrorTypes.key_model_access_denied,
+        param="model",
+        code=403,
+    )
+
+
+def _http_request_scope():
+    return Request({"type": "http", "method": "POST", "path": "/v1/chat/completions", "headers": []})
+
+
+@pytest.mark.asyncio
+async def test_openai_exception_handler_logs_sanitized_model_access_denial(monkeypatch, caplog):
+    monkeypatch.setattr(
+        litellm, "model_access_denied_message", "The model `{model}` is unavailable for this API key or does not exist."
+    )
+
+    with caplog.at_level("WARNING", logger="LiteLLM Proxy"):
+        response = await openai_exception_handler(_http_request_scope(), _model_access_denied_proxy_exception())
+
+    assert response.status_code == 403
+    body = json.loads(response.body)
+    assert "internal-models" not in body["error"]["message"]
+    denial_records = [r for r in caplog.records if "internal-models" in r.getMessage()]
+    assert len(denial_records) == 1
+    assert denial_records[0].levelname == "WARNING"
+    assert "\n" not in denial_records[0].getMessage()
+    assert "\r" not in denial_records[0].getMessage()
+    assert "gpt-5.6WARNING forged log line" in denial_records[0].getMessage()
+
+
+@pytest.mark.asyncio
+@pytest.mark.parametrize("unset_value", [None, ""])
+async def test_openai_exception_handler_no_denial_log_when_message_not_configured(monkeypatch, unset_value, caplog):
+    monkeypatch.setattr(litellm, "model_access_denied_message", unset_value)
+
+    with caplog.at_level("WARNING", logger="LiteLLM Proxy"):
+        response = await openai_exception_handler(_http_request_scope(), _model_access_denied_proxy_exception())
+
+    assert response.status_code == 403
+    assert [r for r in caplog.records if r.levelname == "WARNING" and "internal-models" in r.getMessage()] == []
+
+
+@pytest.mark.asyncio
+async def test_openai_exception_handler_no_denial_log_for_plain_proxy_exception(monkeypatch, caplog):
+    monkeypatch.setattr(
+        litellm, "model_access_denied_message", "The model `{model}` is unavailable for this API key or does not exist."
+    )
+    denial = ProxyException(
+        message="Authentication Error, Invalid proxy server token passed",
+        type=ProxyErrorTypes.auth_error,
+        param="None",
+        code=401,
+    )
+
+    with caplog.at_level("WARNING", logger="LiteLLM Proxy"):
+        response = await openai_exception_handler(_http_request_scope(), denial)
+
+    assert response.status_code == 401
+    assert [r for r in caplog.records if r.levelname == "WARNING"] == []
+
+
+@pytest.mark.asyncio
+async def test_realtime_model_access_denial_logs_sanitized_internal_message(monkeypatch, caplog):
+    monkeypatch.setattr(
+        litellm, "model_access_denied_message", "The model `{model}` is unavailable for this API key or does not exist."
+    )
+    reservation = {"reserved_cost": 0.0, "input_cost": 0.0, "finalized": False, "entries": []}
+
+    with caplog.at_level("WARNING", logger="LiteLLM Proxy"):
+        ws = await _lit6973_drive_realtime_session(
+            reservation,
+            backend_logged_success=False,
+            phase_one_exit="model_access",
+            model_access_exception=_model_access_denied_proxy_exception(),
+        )
+
+    ws.close.assert_awaited_once()
+    assert "internal-models" not in ws.close.await_args.kwargs["reason"]
+    denial_records = [r for r in caplog.records if "internal-models" in r.getMessage()]
+    assert len(denial_records) == 1
+    assert "\n" not in denial_records[0].getMessage()
+    assert "gpt-5.6WARNING forged log line" in denial_records[0].getMessage()
+
+
 @pytest.mark.parametrize("empty_value", [None, ""])
 def test_validate_expose_router_debug_in_errors_empty_restores_true_default(empty_value):
     from litellm.proxy.proxy_server import _validate_general_settings_ui_litellm_value