Merge pull request #35388 from BerriAI/litellm_session_total_duration

fix(spend): sum multi-round session duration in logs UI
This commit is contained in:
Mateo Wang 2026-09-15 17:31:41 -07:00 committed by GitHub
commit aa710dc6a9
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
5 changed files with 157 additions and 7 deletions

View file

@ -176,6 +176,7 @@ class _SessionSpendRow(TypedDict):
api_key: ReadOnly[str]
session_total_count: ReadOnly[int]
session_total_spend: float
session_total_duration_ms: ReadOnly[int]
mcp_tool_call_count: int
mcp_tool_call_spend: float
session_cache_hit_count: ReadOnly[int]
@ -194,6 +195,7 @@ _SESSION_MODEL_NAME_MAX_LEN: Final = 256
class _SessionSpendStats(NamedTuple):
session_total_count: int
session_total_spend: float
session_total_duration_ms: int
mcp_tool_call_count: int
mcp_tool_call_spend: float
session_cache_hit_count: int
@ -4543,6 +4545,12 @@ async def _build_ui_spend_logs_response(
SELECT session_id, api_key,
COUNT(*)::int AS session_total_count,
COALESCE(SUM(spend), 0)::double precision AS session_total_spend,
COALESCE(SUM(
COALESCE(
request_duration_ms,
(EXTRACT(EPOCH FROM ("endTime" - "startTime")) * 1000)::INTEGER
)
), 0)::bigint AS session_total_duration_ms,
COUNT(*) FILTER (
WHERE call_type IN {_MCP_CALL_TYPES_SQL}
)::int AS mcp_tool_call_count,
@ -4584,6 +4592,7 @@ async def _build_ui_spend_logs_response(
(row["session_id"], row["api_key"]): _SessionSpendStats(
session_total_count=int(row.get("session_total_count") or 0),
session_total_spend=float(row.get("session_total_spend") or 0.0),
session_total_duration_ms=int(row.get("session_total_duration_ms") or 0),
mcp_tool_call_count=int(row.get("mcp_tool_call_count") or 0),
mcp_tool_call_spend=float(row.get("mcp_tool_call_spend") or 0.0),
session_cache_hit_count=int(row.get("session_cache_hit_count") or 0),
@ -4615,6 +4624,7 @@ async def _build_ui_spend_logs_response(
row_dict["session_total_count"] = session_stats.session_total_count if session_stats else 1
if session_stats:
row_dict["session_total_spend"] = session_stats.session_total_spend
row_dict["session_total_duration_ms"] = session_stats.session_total_duration_ms
if session_stats.mcp_tool_call_count:
row_dict["mcp_tool_call_count"] = session_stats.mcp_tool_call_count
row_dict["mcp_tool_call_spend"] = session_stats.mcp_tool_call_spend

View file

@ -5353,6 +5353,87 @@ async def test_build_ui_spend_logs_response_sums_multi_round_session_tokens():
assert all(key not in rows[2] for key in token_keys)
@pytest.mark.asyncio
async def test_build_ui_spend_logs_response_sums_multi_round_session_duration():
"""
Regression test: a multi-round session collapses into a single UI row, so that row
must carry the duration of every round summed, not just the representative call's.
Rows written before request_duration_ms existed are NULL, so the aggregate falls back
to endTime - startTime for them.
"""
from litellm.proxy.spend_tracking.spend_management_endpoints import (
_build_ui_spend_logs_response,
)
session_id = "sess-multi-round-duration"
api_key = "hashed-key-xyz"
dict_rows = [
{
"request_id": "req-1",
"session_id": session_id,
"call_type": "completion",
"api_key": api_key,
"spend": 0.01,
"request_duration_ms": 1200,
},
{
"request_id": "req-2",
"session_id": session_id,
"call_type": "completion",
"api_key": api_key,
"spend": 0.02,
"request_duration_ms": 4200,
},
{
"request_id": "req-3",
"session_id": None,
"call_type": "completion",
"api_key": api_key,
"spend": 0.03,
"request_duration_ms": 900,
},
]
mock_prisma = MagicMock()
mock_prisma.db.query_raw = AsyncMock(
return_value=[
{
"session_id": session_id,
"api_key": api_key,
"session_total_count": 2,
"session_total_spend": 0.03,
"session_total_duration_ms": 5400,
"mcp_tool_call_count": 0,
"mcp_tool_call_spend": 0.0,
}
]
)
result = await _build_ui_spend_logs_response(
prisma_client=mock_prisma,
data=dict_rows,
total_records=3,
page=1,
page_size=50,
total_pages=1,
enrich_session_counts=True,
)
rows = result["data"]
session_rows = rows[:2]
assert [row["session_total_duration_ms"] for row in session_rows] == [5400, 5400]
assert all(isinstance(row["session_total_duration_ms"], int) for row in session_rows)
assert [row["request_duration_ms"] for row in rows] == [1200, 4200, 900]
assert "session_total_duration_ms" not in rows[2]
_, call_args, _ = mock_prisma.db.query_raw.mock_calls[0]
sql = " ".join(call_args[0].split())
assert (
'SUM( COALESCE( request_duration_ms, (EXTRACT(EPOCH FROM ("endTime" - "startTime")) * 1000)::INTEGER ) )'
in sql
)
@pytest.mark.asyncio
async def test_build_ui_spend_logs_response_session_cache_hit_count():
"""

View file

@ -73,6 +73,57 @@ describe("Cost column", () => {
expect(screen.queryByText("$0.010000")).not.toBeInTheDocument();
expect(screen.getByText("session total")).toBeInTheDocument();
});
it("does not label the per-call spend a session total when the aggregate is unavailable", () => {
const rowWithoutAggregate: Partial<LogEntry> = {
request_id: "req-session-no-aggregate",
spend: 0.01,
session_id: "sess-1",
session_total_count: 3,
};
renderRows([logEntry(rowWithoutAggregate)]);
expect(screen.getByText("$0.010000")).toBeInTheDocument();
expect(screen.queryByText("session total")).not.toBeInTheDocument();
});
});
describe("Duration column", () => {
const sessionRow: Partial<LogEntry> = {
request_id: "req-session-duration",
request_duration_ms: 1200,
session_id: "sess-1",
session_total_count: 3,
};
it("shows the summed session duration, not the representative call's duration, for a multi-round session", () => {
const aggregatedRow: Partial<LogEntry> = { ...sessionRow, session_total_duration_ms: 5400 };
renderRows([logEntry(aggregatedRow)]);
expect(screen.getByText("5.40")).toBeInTheDocument();
expect(screen.queryByText("1.20")).not.toBeInTheDocument();
expect(screen.getByText("session total")).toBeInTheDocument();
});
it("does not label the per-call duration a session total when the aggregate is unavailable", () => {
renderRows([logEntry(sessionRow)]);
expect(screen.getByText("1.20")).toBeInTheDocument();
expect(screen.queryByText("session total")).not.toBeInTheDocument();
});
it("shows the call's own duration for a single-call session", () => {
const singleCallRow: Partial<LogEntry> = {
...sessionRow,
request_id: "req-single-duration",
session_id: "sess-2",
session_total_count: 1,
session_total_duration_ms: 1200,
};
renderRows([logEntry(singleCallRow)]);
expect(screen.getByText("1.20")).toBeInTheDocument();
});
});
describe("Tokens column", () => {

View file

@ -163,7 +163,8 @@ export const getRequestLogsTableColumns = ({
const mcpCount = log.mcp_tool_call_count || 0;
const mcpSpend = log.mcp_tool_call_spend || 0;
const isMultiCallSession = (log.session_total_count || 1) > 1;
const spend = isMultiCallSession && log.session_total_spend != null ? log.session_total_spend : log.spend;
const sessionTotalSpend = isMultiCallSession ? log.session_total_spend : undefined;
const spend = sessionTotalSpend ?? log.spend;
const money = (
<span>
<MoneyCell value={spend} decimals={6} />
@ -173,7 +174,7 @@ export const getRequestLogsTableColumns = ({
return (
<div className="flex flex-col items-end">
{spend ? <CellTooltip content={`$${String(spend)}`} trigger={money} /> : money}
{isMultiCallSession && <span className="text-[10px] text-muted-foreground">session total</span>}
{sessionTotalSpend != null && <span className="text-[10px] text-muted-foreground">session total</span>}
{mcpCount > 0 && mcpSpend > 0 && (
<span className="text-[10px] text-warning">
incl. {getSpendString(mcpSpend)} from {mcpCount} MCP
@ -190,13 +191,19 @@ export const getRequestLogsTableColumns = ({
enableSorting: true,
meta: { numeric: true },
cell: ({ row }) => {
const ms = row.original.request_duration_ms;
const log = row.original;
const isMultiCallSession = (log.session_total_count || 1) > 1;
const sessionTotalMs = isMultiCallSession ? log.session_total_duration_ms : undefined;
const ms = sessionTotalMs ?? log.request_duration_ms;
if (ms == null) return <span>-</span>;
return (
<CellTooltip
content={`${ms}ms`}
trigger={<span className="max-w-[15ch] truncate inline-block">{(ms / 1000).toFixed(2)}</span>}
/>
<div className="flex flex-col items-end">
<CellTooltip
content={`${ms}ms`}
trigger={<span className="max-w-[15ch] truncate inline-block">{(ms / 1000).toFixed(2)}</span>}
/>
{sessionTotalMs != null && <span className="text-[10px] text-muted-foreground">session total</span>}
</div>
);
},
},

View file

@ -43,6 +43,7 @@ export type LogEntry = {
request_duration_ms?: number;
session_total_count?: number;
session_total_spend?: number;
session_total_duration_ms?: number;
session_total_tokens?: number;
session_total_prompt_tokens?: number;
session_total_completion_tokens?: number;