fix(decisions): log every request field the caller sent on /v1/systemone and /v1/decisions (#47183)

* fix(decisions): log every request field the caller sent on /v1/systemone and /v1/decisions

* fix(decisions): serialize the logged request with model_dump_json so no mutable dict is built

* refactor(decisions): drop the state-only messages pick in function_setup, prepare_call logs the request

* fix(decisions): return the single logged message so no mutable list type is annotated

* fix(decisions): log the caller's raw request fields before validation so a rejected request is still recorded

* fix(decisions): serialize the raw request fields with pydantic_core so question objects and mapping proxies log as JSON

* fix(decisions): log the caller request at the SDK entry so requests rejected before prepare_call are recorded too

* test(decisions): assert the exact BadRequestError for the rejected-questions case

---------

Co-authored-by: devin-ai-integration[bot] <158243242+devin-ai-integration[bot]@users.noreply.github.com>

Backport of #47183 to stable/1.105.x.
Cherry-picked from 53821f6654 (main).

litellm/decisions/call.py

@@ -1,9 +1,11 @@
+import json
 from collections.abc import Mapping, Sequence
 from dataclasses import dataclass, field, replace
 from typing import Final, TypeAlias
 
 import httpx
 from pydantic import ConfigDict, TypeAdapter, ValidationError
+from pydantic_core import to_jsonable_python
 from typing_extensions import assert_never
 
 import litellm
@@ -30,6 +32,7 @@ from litellm.types.decisions import (
     OpenAIDecisionResponse,
     UnsupportedDecisionsRequest,
 )
+from litellm.types.llms.openai import ChatCompletionUserMessage
 from litellm.types.utils import LlmProviders
 from litellm.utils import ProviderConfigManager
 
@@ -148,6 +151,30 @@ def _provider_ir_request(
     return _UnsupportedSafetyIdentifier()
 
 
+_LOGGED_FIELDS_ADAPTER: Final[TypeAdapter[Mapping[str, object]]] = TypeAdapter(Mapping[str, object])
+
+
+def _jsonable_fallback(value: object) -> object:
+    return dict(_LOGGED_FIELDS_ADAPTER.validate_python(value)) if isinstance(value, Mapping) else str(value)
+
+
+def _logged_request_message(caller_request: object) -> ChatCompletionUserMessage:
+    caller_fields: Final = _LOGGED_FIELDS_ADAPTER.validate_python(
+        to_jsonable_python(caller_request, fallback=_jsonable_fallback)
+    )
+    sent_fields: Final = json.dumps(
+        dict((name, value) for name, value in caller_fields.items() if value not in (None, [], {}))
+    )
+    return ChatCompletionUserMessage(role="user", content=sent_fields)
+
+
+def log_caller_request(kwargs: Mapping[str, object], caller_request: object) -> None:
+    """Record every request field the caller sent as the logged `messages`, before any validation."""
+    logging_obj: Final = kwargs.get("litellm_logging_obj")
+    if isinstance(logging_obj, LiteLLMLoggingObj):
+        logging_obj.update_messages([_logged_request_message(caller_request)])
+
+
 def prepare_call(
     *,
     model: str,

litellm/decisions/main.py

@@ -13,6 +13,7 @@ from litellm.decisions.call import (
     SystemOneQuestions,
     SystemOneRequestFields,
     asend,
+    log_caller_request,
     prepare_call,
     send,
 )
@@ -24,6 +25,7 @@ _SYSTEMONE_QUESTIONS_ADAPTER: Final[TypeAdapter[SystemOneQuestions | None]] = Ty
 _OPENAI_QUESTIONS_ADAPTER: Final[TypeAdapter[OpenAIDecisionQuestions | None]] = TypeAdapter(
     OpenAIDecisionQuestions | None
 )
+_SYSTEMONE_FIELDS: Final = frozenset({"state"})
 
 
 def _request_fields(
@@ -59,6 +61,14 @@ def _prepare_decisions_call(
     extra_headers: Mapping[str, str] | None,
     kwargs: Mapping[str, object],
 ) -> DecisionsCall:
+    log_caller_request(
+        kwargs,
+        {
+            "input": decision_input,
+            "questions": questions,
+            **{key: kwargs[key] for key in _SYSTEMONE_FIELDS if key in kwargs},
+        },
+    )
     return prepare_call(
         model=model,
         fields=_request_fields(decision_input, questions, kwargs),

litellm/systemone/main.py

@@ -8,6 +8,7 @@ from litellm.decisions.call import (
     SystemOneQuestions,
     SystemOneRequestFields,
     asend,
+    log_caller_request,
     prepare_call,
     reject_other_format,
     send,
@@ -29,10 +30,12 @@ def _prepare_systemone_call(
     extra_headers: Mapping[str, str] | None,
     kwargs: Mapping[str, object],
 ) -> DecisionsCall:
+    fields: Final = SystemOneRequestFields(state=state, questions=questions)
+    log_caller_request(kwargs, fields)
     reject_other_format(model=model, kwargs=kwargs, field_name="input", other_function="decisions")
     return prepare_call(
         model=model,
-        fields=SystemOneRequestFields(state=state, questions=questions),
+        fields=fields,
         safety_identifier=safety_identifier,
         api_key=api_key,
         api_base=api_base,

litellm/utils.py

@@ -973,10 +973,6 @@ def _ocr_document_summary(document: object) -> str:
 
 # Runs once per call to check if the user wants to send their data anywhere - PostHog/Sentry/Slack/etc.
 
-_DECISION_CALL_TYPES: Final[frozenset[str]] = frozenset(
-    (CallTypes.decisions.value, CallTypes.adecisions.value, CallTypes.systemone.value, CallTypes.asystemone.value)
-)
-
 
 def function_setup(
     original_function: str,
@@ -1224,9 +1220,6 @@ def function_setup(
                 if isinstance(search_query, list)
                 else search_query
             )
-        elif call_type in _DECISION_CALL_TYPES:
-            decisions_state: Final = args[1] if len(args) > 1 else kwargs.get("state") or kwargs.get("input") or ""
-            messages = decisions_state if isinstance(decisions_state, str) else json.dumps(decisions_state, default=str)
         elif call_type in (CallTypes.image_edit.value, CallTypes.aimage_edit.value):
             messages = args[1] if len(args) > 1 else kwargs.get("prompt")
         elif call_type in (CallTypes.ocr.value, CallTypes.aocr.value):

tests/unit/decisions/test_call.py

@@ -0,0 +1,102 @@
+import json
+from collections.abc import Mapping
+from datetime import datetime, timezone
+from typing import Final
+
+import pytest
+
+import litellm
+from litellm.decisions.main import _prepare_decisions_call
+from litellm.litellm_core_utils.litellm_logging import Logging
+from litellm.systemone.main import _prepare_systemone_call
+
+QUESTION_TEXT: Final = "Is this about a billing problem?"
+CONNECTION: Final = {
+    "model": "hosted_vllm/jev-fake",
+    "safety_identifier": None,
+    "api_key": "fake-provider-key",
+    "api_base": "http://127.0.0.1:4010",
+    "timeout": None,
+    "custom_llm_provider": None,
+    "extra_headers": None,
+}
+
+
+def _logging_obj(call_type: str) -> Logging:
+    return Logging(
+        model="hosted_vllm/jev-fake",
+        messages="placeholder",
+        stream=False,
+        call_type=call_type,
+        start_time=datetime.now(timezone.utc),
+        litellm_call_id="lit-9659",
+        function_id="lit-9659",
+    )
+
+
+def _logged_request(logging_obj: Logging) -> Mapping[str, object]:
+    messages: Final = logging_obj.model_call_details["messages"]
+    assert len(messages) == 1 and messages[0]["role"] == "user"
+    return json.loads(messages[0]["content"])
+
+
+def test_systemone_logs_every_request_field_the_caller_sent():
+    logging_obj: Final = _logging_obj("asystemone")
+
+    _prepare_systemone_call(
+        **CONNECTION,
+        state={"message": "My card was charged twice."},
+        questions={"billing": {"type": "noul", "instructions": QUESTION_TEXT}},
+        kwargs={"litellm_logging_obj": logging_obj},
+    )
+
+    logged: Final = _logged_request(logging_obj)
+    assert logged["state"] == {"message": "My card was charged twice."}
+    assert logged["questions"]["billing"]["instructions"] == QUESTION_TEXT
+    assert set(logged) == {"state", "questions"}
+
+
+def test_decisions_logs_every_request_field_the_caller_sent():
+    logging_obj: Final = _logging_obj("adecisions")
+
+    _prepare_decisions_call(
+        **CONNECTION,
+        decision_input="My card was charged twice.",
+        questions=[{"type": "predicate", "instructions": QUESTION_TEXT}],
+        kwargs={"litellm_logging_obj": logging_obj},
+    )
+
+    logged: Final = _logged_request(logging_obj)
+    assert logged["input"] == "My card was charged twice."
+    assert logged["questions"][0]["instructions"] == QUESTION_TEXT
+    assert set(logged) == {"input", "questions"}
+
+
+def test_request_is_logged_even_when_it_is_rejected_before_the_provider_call():
+    logging_obj: Final = _logging_obj("asystemone")
+
+    with pytest.raises(litellm.BadRequestError):
+        _prepare_systemone_call(
+            **CONNECTION,
+            state={"message": "My card was charged twice."},
+            questions={"billing": {"type": "noul", "instructions": QUESTION_TEXT}},
+            kwargs={"litellm_logging_obj": logging_obj, "input": "sent to the wrong function"},
+        )
+
+    logged: Final = _logged_request(logging_obj)
+    assert logged["questions"]["billing"]["instructions"] == QUESTION_TEXT
+
+
+def test_decisions_request_is_logged_even_when_its_questions_fail_validation():
+    logging_obj: Final = _logging_obj("adecisions")
+
+    with pytest.raises(litellm.BadRequestError):
+        _prepare_decisions_call(
+            **CONNECTION,
+            decision_input="My card was charged twice.",
+            questions=[{"type": "not-a-question-type", "instructions": QUESTION_TEXT}],
+            kwargs={"litellm_logging_obj": logging_obj},
+        )
+
+    logged: Final = _logged_request(logging_obj)
+    assert logged["questions"][0]["instructions"] == QUESTION_TEXT