From b99f0c812f0d820242f9ac8988213683cdcf0d2f Mon Sep 17 00:00:00 2001 From: yassin Date: Tue, 15 Sep 2026 23:36:12 +0000 Subject: [PATCH] fix(proxy): log configured model access denial only at the auth error boundary Move the WARNING that carries the internal denial detail out of the message formatter and into the auth exception handler. The denial exceptions now carry internal_message so access-group probes and fallback paths that catch and recover from the denial no longer log a false denial for an allowed request Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> --- litellm/proxy/_types.py | 13 ++ litellm/proxy/auth/auth_checks.py | 47 ++++---- litellm/proxy/auth/auth_exception_handler.py | 13 ++ litellm/proxy/auth/handle_jwt.py | 23 ++-- litellm/proxy/auth/model_access_denied.py | 19 +++ .../proxy/auth/test_auth_checks.py | 49 ++++---- .../proxy/auth/test_auth_exception_handler.py | 111 +++++++++++++++++- .../proxy/auth/test_handle_jwt.py | 9 +- 8 files changed, 225 insertions(+), 59 deletions(-) create mode 100644 litellm/proxy/auth/model_access_denied.py diff --git a/litellm/proxy/_types.py b/litellm/proxy/_types.py index d4eda1c9540..8949433dc34 100644 --- a/litellm/proxy/_types.py +++ b/litellm/proxy/_types.py @@ -4030,6 +4030,19 @@ class ProxyException(Exception): return error_dict +class ModelAccessDeniedProxyException(ProxyException): + def __init__( + self, + message: str, + internal_message: str, + type: str, + param: str | None, + code: int | str | None, + ) -> None: + super().__init__(message=message, type=type, param=param, code=code) + self.internal_message: Final = internal_message + + class CommonProxyErrors(str, enum.Enum): db_not_connected_error = ( "DB not connected. This endpoint needs a database; set DATABASE_URL to a " diff --git a/litellm/proxy/auth/auth_checks.py b/litellm/proxy/auth/auth_checks.py index b13214eaf5e..80bb1e3b319 100644 --- a/litellm/proxy/auth/auth_checks.py +++ b/litellm/proxy/auth/auth_checks.py @@ -32,7 +32,6 @@ from litellm.constants import ( DEFAULT_MAX_RECURSE_DEPTH, EMAIL_BUDGET_ALERT_MAX_SPEND_ALERT_PERCENTAGE, END_USER_RESTRICTED_REGISTRY_MAX_SIZE, - MODEL_ACCESS_DENIED_MESSAGE_MODEL_PLACEHOLDER, MODEL_ACCESS_GROUP_REGISTRY_MAX_SIZE, REGISTRY_ERROR_NEGATIVE_CACHE_TTL, TAG_REGISTRY_MAX_SIZE, @@ -61,6 +60,7 @@ from litellm.proxy._types import ( LiteLLM_UserTable, LiteLLMRoutes, LitellmUserRoles, + ModelAccessDeniedProxyException, NewTeamRequest, ProxyErrorTypes, ProxyException, @@ -72,6 +72,7 @@ from litellm.proxy.auth.budget_throttle import ( budget_throttle_percentage, should_throttle_budget_exceeded, ) +from litellm.proxy.auth.model_access_denied import client_facing_model_access_denied_message from litellm.proxy.auth.route_checks import RouteChecks from litellm.proxy.common_utils.auth_cache_invalidation_pubsub import publish_auth_cache_invalidation from litellm.proxy.common_utils.cache_pydantic_utils import CacheCodec @@ -4034,14 +4035,6 @@ async def _get_agent_ids_from_access_groups( ) -def client_facing_model_access_denied_message(internal_message: str, model: str | list[str]) -> str: - template: Final = litellm.model_access_denied_message - if not template: - return internal_message - verbose_proxy_logger.warning(internal_message.replace("\r", "").replace("\n", "")) - return template.replace(MODEL_ACCESS_DENIED_MESSAGE_MODEL_PLACEHOLDER, str(model)) - - def _resolve_all_team_model_sentinel_for_auth_check( models: list[str], llm_router: Router | None, @@ -4163,11 +4156,13 @@ def _can_object_call_model( ): return True - raise ProxyException( - message=client_facing_model_access_denied_message( - internal_message=f"{object_type} not allowed to access model. This {object_type} can only access models={models}. Tried to access {model}", - model=model, - ), + internal_message: Final = ( + f"{object_type} not allowed to access model. This {object_type} can only access models={models}. " + f"Tried to access {model}" + ) + raise ModelAccessDeniedProxyException( + message=client_facing_model_access_denied_message(internal_message=internal_message, model=model), + internal_message=internal_message, type=ProxyErrorTypes.get_model_access_error_type_for_object(object_type=object_type), param="model", code=status.HTTP_403_FORBIDDEN, @@ -4792,11 +4787,13 @@ async def can_user_call_model( return True if SpecialModelNames.no_default_models.value in user_object.models: - raise ProxyException( - message=client_facing_model_access_denied_message( - internal_message=f"User not allowed to access model. No default model access, only team models allowed. Tried to access {model}", - model=model, - ), + internal_message: Final = ( + f"User not allowed to access model. No default model access, only team models allowed. " + f"Tried to access {model}" + ) + raise ModelAccessDeniedProxyException( + message=client_facing_model_access_denied_message(internal_message=internal_message, model=model), + internal_message=internal_message, type=ProxyErrorTypes.key_model_access_denied, param="model", code=status.HTTP_403_FORBIDDEN, @@ -5397,11 +5394,13 @@ async def _check_team_member_model_access( team_id=team_object.team_id, ) except ProxyException: - raise ProxyException( - message=client_facing_model_access_denied_message( - internal_message=f"Team member not allowed to access model. User={valid_token.user_id}, Team={team_object.team_id}, Model={model}. Allowed member models = {member_allowed_models}", - model=model, - ), + internal_message: Final = ( + f"Team member not allowed to access model. User={valid_token.user_id}, Team={team_object.team_id}, " + f"Model={model}. Allowed member models = {member_allowed_models}" + ) + raise ModelAccessDeniedProxyException( + message=client_facing_model_access_denied_message(internal_message=internal_message, model=model), + internal_message=internal_message, type=ProxyErrorTypes.team_model_access_denied, param="model", code=status.HTTP_403_FORBIDDEN, diff --git a/litellm/proxy/auth/auth_exception_handler.py b/litellm/proxy/auth/auth_exception_handler.py index 661b6a83c38..4a764cae6cc 100644 --- a/litellm/proxy/auth/auth_exception_handler.py +++ b/litellm/proxy/auth/auth_exception_handler.py @@ -15,6 +15,7 @@ from litellm.integrations.otel.runtime import seed_request_identity from litellm.litellm_core_utils.core_helpers import is_expected_client_error from litellm.proxy._types import ( LitellmUserRoles, + ModelAccessDeniedProxyException, ProxyErrorTypes, ProxyException, UserAPIKeyAuth, @@ -25,6 +26,7 @@ from litellm.proxy.auth.auth_utils import ( mark_invalid_virtual_key_error, normalize_request_route, ) +from litellm.proxy.auth.model_access_denied import ModelAccessDeniedHTTPException from litellm.proxy.db.exception_handler import PrismaDBExceptionHandler from litellm.types.services import ServiceTypes @@ -75,6 +77,14 @@ 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 @@ -166,6 +176,9 @@ 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 diff --git a/litellm/proxy/auth/handle_jwt.py b/litellm/proxy/auth/handle_jwt.py index 6e5e75a5e20..ea6d52b28f0 100644 --- a/litellm/proxy/auth/handle_jwt.py +++ b/litellm/proxy/auth/handle_jwt.py @@ -52,6 +52,10 @@ from litellm.proxy._types import ( UserAPIKeyAuth, ) from litellm.proxy.auth.auth_checks import can_team_access_model +from litellm.proxy.auth.model_access_denied import ( + ModelAccessDeniedHTTPException, + client_facing_model_access_denied_message, +) from litellm.proxy.auth.resolvers.grants import GrantResolver, UserLookup, canonical_user_id from litellm.proxy.auth.route_checks import RouteChecks from litellm.proxy.auth.team_grants import team_model_aliases @@ -66,7 +70,6 @@ from litellm.types.agents import AgentResponse from .auth_checks import ( _allowed_routes_check, allowed_routes_check, - client_facing_model_access_denied_message, get_actual_routes, get_end_user_object, get_org_object, @@ -1338,12 +1341,13 @@ class JWTAuthManager: return True if model not in role_based_models: - raise HTTPException( + internal_message: Final = ( + f"Role={rbac_role} not allowed to call model={model}. Allowed models={role_based_models}" + ) + raise ModelAccessDeniedHTTPException( + internal_message=internal_message, status_code=403, - detail=client_facing_model_access_denied_message( - internal_message=f"Role={rbac_role} not allowed to call model={model}. Allowed models={role_based_models}", - model=model, - ), + detail=client_facing_model_access_denied_message(internal_message=internal_message, model=model), ) return True @@ -1372,12 +1376,13 @@ class JWTAuthManager: return if requested_model not in allowed_models: - raise HTTPException( + internal_message: Final = f"model={requested_model} not allowed. Allowed_models={allowed_models}" + raise ModelAccessDeniedHTTPException( + internal_message=internal_message, status_code=403, detail={ "error": client_facing_model_access_denied_message( - internal_message=f"model={requested_model} not allowed. Allowed_models={allowed_models}", - model=requested_model, + internal_message=internal_message, model=requested_model ) }, ) diff --git a/litellm/proxy/auth/model_access_denied.py b/litellm/proxy/auth/model_access_denied.py new file mode 100644 index 00000000000..8164e06c42a --- /dev/null +++ b/litellm/proxy/auth/model_access_denied.py @@ -0,0 +1,19 @@ +from typing import Final + +from fastapi import HTTPException + +import litellm +from litellm.constants import MODEL_ACCESS_DENIED_MESSAGE_MODEL_PLACEHOLDER + + +def client_facing_model_access_denied_message(internal_message: str, model: str | list[str]) -> str: + template: Final = litellm.model_access_denied_message + if not template: + return internal_message + return template.replace(MODEL_ACCESS_DENIED_MESSAGE_MODEL_PLACEHOLDER, str(model)) + + +class ModelAccessDeniedHTTPException(HTTPException): + def __init__(self, internal_message: str, status_code: int, detail: str | dict[str, str]) -> None: + super().__init__(status_code=status_code, detail=detail) + self.internal_message: Final = internal_message diff --git a/tests/test_litellm/proxy/auth/test_auth_checks.py b/tests/test_litellm/proxy/auth/test_auth_checks.py index 0052cfb66d3..0677fb8af29 100644 --- a/tests/test_litellm/proxy/auth/test_auth_checks.py +++ b/tests/test_litellm/proxy/auth/test_auth_checks.py @@ -25,6 +25,7 @@ from litellm.proxy._types import ( LiteLLM_TeamTable, LiteLLM_UserTable, LitellmUserRoles, + ModelAccessDeniedProxyException, ProxyErrorTypes, ProxyException, SSOUserDefinedValues, @@ -1682,11 +1683,11 @@ def test_can_object_call_model_no_access_to_alias_or_underlying(): _DENIED_MESSAGE_TEMPLATE: Final = "The model `{model}` is unavailable for this API key or does not exist." -def test_can_object_call_model_denial_uses_configured_message_and_logs_detail(monkeypatch, caplog): +def test_can_object_call_model_denial_uses_configured_message_and_keeps_detail_on_exception(monkeypatch, caplog): monkeypatch.setattr(litellm, "model_access_denied_message", _DENIED_MESSAGE_TEMPLATE) - with caplog.at_level("WARNING", logger="LiteLLM Proxy"): - with pytest.raises(ProxyException) as exc_info: + with caplog.at_level("DEBUG", logger="LiteLLM Proxy"): + with pytest.raises(ModelAccessDeniedProxyException) as exc_info: _can_object_call_model( model="anthropic-sonnet-4-5", llm_router=None, @@ -1700,28 +1701,30 @@ def test_can_object_call_model_denial_uses_configured_message_and_logs_detail(mo assert exc_info.value.type == ProxyErrorTypes.key_model_access_denied assert exc_info.value.param == "model" assert int(exc_info.value.code) == status.HTTP_403_FORBIDDEN - assert "internal-models" in caplog.text - assert "anthropic-sonnet-4-5" in caplog.text - - -def test_can_object_call_model_denial_log_strips_newlines_from_requested_model(monkeypatch, caplog): - monkeypatch.setattr(litellm, "model_access_denied_message", _DENIED_MESSAGE_TEMPLATE) - - with caplog.at_level("WARNING", logger="LiteLLM Proxy"): - with pytest.raises(ProxyException): - _can_object_call_model( - model="gpt-5.6\r\nWARNING forged log line", - llm_router=None, - models=["internal-models"], - object_type="key", - ) - - denial_records = [r for r in caplog.records if "not allowed to access model" in r.getMessage()] - assert len(denial_records) == 1 - assert denial_records[0].getMessage() == ( + assert exc_info.value.internal_message == ( "key not allowed to access model. This key can only access models=['internal-models']. " - "Tried to access gpt-5.6WARNING forged log line" + "Tried to access anthropic-sonnet-4-5" ) + assert "internal-models" not in caplog.text + + +@pytest.mark.asyncio +async def test_access_group_fallback_grant_does_not_log_a_denial(monkeypatch, caplog): + from litellm.proxy.auth.auth_checks import can_team_access_model + + monkeypatch.setattr(litellm, "model_access_denied_message", _DENIED_MESSAGE_TEMPLATE) + team_object = LiteLLM_TeamTable(team_id="team-123", models=["direct-model"], access_group_ids=["ag-1"]) + + with ( + patch( # test-quality-ok: access-group lookup has no dependency-injection seam + "litellm.proxy.auth.auth_checks._get_models_from_access_groups", + new=AsyncMock(return_value=["group-model"]), + ), + caplog.at_level("DEBUG", logger="LiteLLM Proxy"), + ): + assert await can_team_access_model("group-model", team_object, None) is True + + assert "not allowed to access model" not in caplog.text @pytest.mark.parametrize("unset_value", [None, ""]) diff --git a/tests/test_litellm/proxy/auth/test_auth_exception_handler.py b/tests/test_litellm/proxy/auth/test_auth_exception_handler.py index 6e9770bced8..602c074ee66 100644 --- a/tests/test_litellm/proxy/auth/test_auth_exception_handler.py +++ b/tests/test_litellm/proxy/auth/test_auth_exception_handler.py @@ -26,11 +26,18 @@ from prisma.errors import ( ) +import litellm from litellm._logging import verbose_proxy_logger from litellm.constants import INVALID_VIRTUAL_KEY_ERROR_MARKER from litellm.exceptions import BudgetExceededError -from litellm.proxy._types import ProxyErrorTypes, ProxyException, UserAPIKeyAuth +from litellm.proxy._types import ( + ModelAccessDeniedProxyException, + ProxyErrorTypes, + ProxyException, + UserAPIKeyAuth, +) from litellm.proxy.auth.auth_exception_handler import UserAPIKeyAuthExceptionHandler +from litellm.proxy.auth.model_access_denied import ModelAccessDeniedHTTPException class _EngineHttp500: @@ -982,3 +989,105 @@ async def test_handle_authentication_error_traceback_only_for_unexpected_errors( assert records[0].levelname == expect_level expected_logger_name = "LiteLLM Proxy.stdout" if expect_level == "WARNING" else "LiteLLM Proxy" assert records[0].name == expected_logger_name + + +_DENIED_MESSAGE_TEMPLATE = "The model `{model}` is unavailable for this API key or does not exist." + + +def _denied_proxy_exception() -> ModelAccessDeniedProxyException: + 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=status.HTTP_403_FORBIDDEN, + ) + + +def _denied_jwt_exception() -> ModelAccessDeniedHTTPException: + return ModelAccessDeniedHTTPException( + internal_message="Role=engineer not allowed to call model=gpt-5.6\r\nWARNING forged log line. " + "Allowed models=['internal-models']", + status_code=status.HTTP_403_FORBIDDEN, + detail="The model `gpt-5.6` is unavailable for this API key or does not exist.", + ) + + +@pytest.mark.asyncio +@pytest.mark.parametrize( + "make_denial", + [ + pytest.param(_denied_proxy_exception, id="proxy_exception"), + 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): + monkeypatch.setattr(litellm, "model_access_denied_message", _DENIED_MESSAGE_TEMPLATE) + handler = UserAPIKeyAuthExceptionHandler() + denial = make_denial() + + with ( + patch( # test-quality-ok: handler reads proxy_server globals at call time + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + new_callable=AsyncMock, + return_value=None, + ), + patch( # test-quality-ok: handler reads proxy_server globals at call time + "litellm.proxy.auth.auth_exception_handler.seed_request_identity", + ), + patch( # test-quality-ok: handler reads proxy_server globals at call time + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + caplog.at_level("WARNING", logger="LiteLLM Proxy"), + pytest.raises(ProxyException) 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() + + +@pytest.mark.asyncio +@pytest.mark.parametrize("unset_value", [None, ""]) +async def test_handle_authentication_error_no_extra_denial_log_when_message_not_configured( + monkeypatch, unset_value, caplog +): + monkeypatch.setattr(litellm, "model_access_denied_message", unset_value) + handler = UserAPIKeyAuthExceptionHandler() + denial = ModelAccessDeniedProxyException( + message="key not allowed to access model. This key can only access models=['internal-models']. " + "Tried to access gpt-5.6", + internal_message="key not allowed to access model. This key can only access models=['internal-models']. " + "Tried to access gpt-5.6", + type=ProxyErrorTypes.key_model_access_denied, + param="model", + code=status.HTTP_403_FORBIDDEN, + ) + + with ( + patch( # test-quality-ok: handler reads proxy_server globals at call time + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + new_callable=AsyncMock, + return_value=None, + ), + patch( # test-quality-ok: handler reads proxy_server globals at call time + "litellm.proxy.auth.auth_exception_handler.seed_request_identity", + ), + patch( # test-quality-ok: handler reads proxy_server globals at call time + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + caplog.at_level("WARNING", logger="LiteLLM Proxy"), + pytest.raises(ProxyException) as exc_info, + ): + await handler._handle_authentication_error(denial, MagicMock(), {}, "/v1/chat/completions", None, "sk-bad-key") + + assert "internal-models" in str(exc_info.value.message) + assert [r for r in caplog.records if r.levelname == "WARNING" and "internal-models" in r.getMessage()] == [] diff --git a/tests/test_litellm/proxy/auth/test_handle_jwt.py b/tests/test_litellm/proxy/auth/test_handle_jwt.py index 921472f2f43..9fab1e1785a 100644 --- a/tests/test_litellm/proxy/auth/test_handle_jwt.py +++ b/tests/test_litellm/proxy/auth/test_handle_jwt.py @@ -37,6 +37,7 @@ from litellm.proxy.auth.handle_jwt import ( JWTHandler, NoMatchingJWTPublicKeyError, ) +from litellm.proxy.auth.model_access_denied import ModelAccessDeniedHTTPException from litellm.types.agents import AgentResponse @@ -6990,7 +6991,7 @@ def test_can_rbac_role_call_model_denial_honors_configured_message(monkeypatch, ] } - with pytest.raises(HTTPException) as exc_info: + with pytest.raises(ModelAccessDeniedHTTPException) as exc_info: JWTAuthManager.can_rbac_role_call_model( rbac_role=LitellmUserRoles.INTERNAL_USER, general_settings=general_settings, @@ -6999,6 +7000,9 @@ def test_can_rbac_role_call_model_denial_honors_configured_message(monkeypatch, assert exc_info.value.status_code == 403 assert exc_info.value.detail == expected_detail + assert exc_info.value.internal_message == ( + "Role=internal_user not allowed to call model=gpt-5.6. Allowed models=['gpt-5.6-mini']" + ) @pytest.mark.parametrize( @@ -7012,7 +7016,7 @@ def test_can_rbac_role_call_model_denial_honors_configured_message(monkeypatch, def test_check_scope_based_access_denial_honors_configured_message(monkeypatch, configured_message, expected_error): monkeypatch.setattr(litellm, "model_access_denied_message", configured_message) - with pytest.raises(HTTPException) as exc_info: + with pytest.raises(ModelAccessDeniedHTTPException) as exc_info: JWTAuthManager.check_scope_based_access( scope_mappings=[ScopeMapping(scope="litellm.api.consumer", models=["gpt-5.6-mini"])], scopes=["litellm.api.consumer"], @@ -7022,3 +7026,4 @@ def test_check_scope_based_access_denial_honors_configured_message(monkeypatch, assert exc_info.value.status_code == 403 assert exc_info.value.detail == {"error": expected_error} + assert exc_info.value.internal_message == "model=gpt-5.6 not allowed. Allowed_models=['gpt-5.6-mini']"