perf: build log messages lazily so filtered-out log records cost nothing

[Classic298]

TLDR

Fixes: #35699

Problem this solves:

• 2877 logging calls build their message before the level check
• discarded debug records still cost full string interpolation
• worst sites stringify whole message lists per request
• cost grows with conversation length, paid on every call

How it solves it:

• pass values as %-style args instead of f-strings
• interpolation moves into record.getMessage(), after the level check
• emitted output is byte-identical when the level is turned up
• a test fails on any new eager logging call

Relevant issues

Linear ticket

Pre-Submission checklist

• I have added meaningful tests
• My PR passes all CI/CD checks (e.g., lint, format, unit tests)
• My PR's scope is as isolated as possible; it only solves 1 specific problem
• I have received a Greptile Confidence Score of at least 4/5 before requesting a maintainer review

Rebase

Rebased onto litellm_internal_staging at cb8c734. The import failure this description used to call out, Union used without being imported in litellm/llms/openai/common_utils.py, landed on staging in #35704, so it is no longer in the way and CI here is no longer held back by it

Two files conflicted and staging won both. litellm/integrations/rubrik.py had been refactored on staging, so staging's copy was taken wholesale and the rewrite re-applied to the 16 logging calls in it. litellm/proxy/litellm_pre_call_utils.py keeps staging's redact_credential_headers(_headers) call and defers only the interpolation, so the credential redaction on that debug line is preserved. Staging's 21 new commits raise the eager-call count at the parent from 2877 to 2884; this branch is at 0

Three things were re-verified against the new parent rather than assumed. Rendering every logging call on both sides with sentinel values, 4544 interpolating calls match byte for byte on message text, argument order, !r to %r conversion and keyword arguments, with zero mismatches; the 205 calls that checker cannot canonicalise (a non-literal message, an already %-style call, or an exempt format spec) are AST-identical to staging and so were never touched. Normalising every logging call to an opaque placeholder and diffing the ASTs leaves 409 of the 410 changed files identical to staging, the sole exception being the test file, which is what rules out anything outside a logging call having changed. Reverting one file to its staging version makes the new test fail and restoring it makes all 11 pass, so the gate still discriminates on the rebased tree

The timings below were measured at 66bc703 and have not been re-run since the rebase

A second commit fixes 17 tests across 9 files that the rewrite broke. They asserted on a mocked logger's call.args[0], which no longer holds the interpolated values, so they were failing on the message text rather than on behaviour. Each now renders the record the way logging does before asserting, which makes them correct under both the eager and the lazy form. Exception objects do not compare equal, so the three assert_any_call sites carrying an exception became a membership check against the rendered calls rather than an exact-argument match

One of those is worth calling out because the repair also closed a hole. tests/test_litellm/experimental_mcp_client/test_mcp_client.py asserts that MCP tool arguments are never logged, and its helper read args[0] alone. Under the rewrite a secret passed as a lazy argument never appears there, so the assertion had gone blind. Leaking the secret lazily on purpose, the old helper passes while the secret is being logged and the rendered helper fails, so that check is doing real work again

Screenshots / Proof of Fix

Measured on the two trees at 66bc703, CPython 3.12, loggers at INFO with a NullHandler, which is what the proxy runs by default. Requests go through mock_response so the timings are litellm's own in-process work with no provider latency mixed in. A single completion executes 10 logging calls on this path, 8 of them debug records that are discarded.

litellm.completion, median over 1500 iterations, best of 4 runs:

conversation	payload	before	after	change
4 messages	4.4 kB	0.326 ms	0.313 ms	4.2% faster
20 messages	22 kB	0.392 ms	0.347 ms	11.3% faster
60 messages	67 kB	0.490 ms	0.381 ms	22.3% faster

CPU time per completion, which is the number that actually matters for a proxy, tracks it closely: 0.396 to 0.385 ms at 4 messages, 0.479 to 0.427 ms at 20, and 0.625 to 0.490 ms at 60. That last one is 0.135 ms of CPU freed per request, or 0.135 seconds of CPU per thousand requests

Peak memory traced through one completion, via tracemalloc, drops because the discarded strings are never built: 30.6 to 22.3 kB at 4 messages, 79.3 to 26.7 kB at 20, and 205.6 to 42.3 kB at 60. The savings scale with payload size for the same reason the CPU savings do

Through Router.acompletion, which is what the proxy calls, a 20-message conversation goes from 0.929 to 0.886 ms wall and a 60-message one from 1.074 to 0.977 ms wall, 9.1% faster with 8.6% less CPU

Concurrency does not change the per-request saving, it multiplies it. Batches of concurrent acompletion calls on a 20-message conversation, best of 15 rounds:

batch	before	after	change	saved per request
1	1.25 ms	1.22 ms	2.4%	30 us
8	5.24 ms	4.69 ms	10.5%	69 us
32	16.44 ms	14.77 ms	10.1%	52 us
128	65.49 ms	59.86 ms	8.6%	44 us

To be explicit about what this is and is not: against a real provider taking seconds to respond, a tenth of a millisecond is invisible in end-to-end latency. What it buys is CPU headroom per request, which is throughput on a busy proxy, and it costs nothing to take

The single line in token_counter, which stringifies the entire message list on a function reachable from cost calculation, streaming chunk assembly and compression, in isolation:

conversation	before	after
4 messages	5.79 us	0.07 us
20 messages	26.25 us	0.07 us
60 messages	77.02 us	0.07 us

For output equivalence I rendered every one of the 2877 rewritten call sites both ways, feeding sentinel values whose str and repr contain percent signs, quotes, braces and %(name)s, and pushing the new form through a real logging.Logger. All 2877 render byte-identically. To confirm it by hand, run the proxy at both commits and diff the logs:

python litellm/proxy/proxy_cli.py --config litellm/proxy/dev_config.yaml --detailed_debug 2>&1 | tee litellm-$(git rev-parse --short HEAD).log

curl -s http://localhost:4000/v1/chat/completions -H 'Authorization: Bearer sk-1234' -H 'Content-Type: application/json' -d '{"model":"gpt-4o","messages":[{"role":"user","content":"say hi"}]}'

Type

🚄 Infrastructure

Changes

Every logging call on verbose_logger, verbose_proxy_logger, verbose_router_logger and the two module-level stdlib loggers now passes its values as %-style arguments rather than interpolating them into an f-string first. This covers debug, info, warning, error and exception, since the message is built at the call site regardless of level and any record the level check drops has already paid for it. The rewrite was mechanical and is net 228 lines shorter, because multi-line f-strings collapse to one line

f-strings carrying a format spec are left alone, 22 sites in total. %-style has no faithful equivalent for something like {ratio:.1%}, and every one of them interpolates a scalar rather than a payload, so there is nothing meaningful to reclaim

tests/test_litellm/test_logging.py gains a test that parses the package and fails on any logging call passing an f-string, exempting the format-spec case. It reports 2884 failures against the parent commit and passes on this one, so reverting any single site reintroduces a failure

Final Attestation

• The tests check the right things, including the edge cases, and regressions in the respective real-world customer use-cases are not possible after this PR

[Classic298]

@greptile-apps

[greptile-apps]

Greptile Summary

The PR mechanically converts LiteLLM diagnostic logging from eager f-string interpolation to deferred stdlib logging arguments and updates affected assertions

• Rewrites logging calls across the SDK, proxy, routing, providers, caching, and integrations
• Adds an AST-based regression test preventing direct eager f-strings in recognized logging calls
• Updates mocked-logger assertions to inspect rendered messages

Confidence Score: 5/5

The PR appears safe to merge

No blocking failure remains

Important Files Changed

Filename	Overview
tests/test_litellm/test_logging.py	Adds package-wide AST enforcement against direct eager f-string construction in recognized logging calls
litellm/litellm_core_utils/litellm_logging.py	Converts internal diagnostic logging to deferred positional interpolation without changing callback payload construction
litellm/proxy/proxy_server.py	Mechanically defers interpolation for proxy diagnostic logs while retaining their values and levels
litellm/router.py	Converts router logging calls to standard lazy interpolation without changing routing behavior
tests/test_litellm/experimental_mcp_client/test_mcp_client.py	Renders mocked lazy logger calls before checking that sensitive MCP arguments are absent

_{Reviews (3): Last reviewed commit: "test: assert on rendered log messages so..." | Re-trigger Greptile}

[Classic298]

litellm_internal_staging at 66bc703 does not import on Python 3.10 through 3.13: litellm/llms/openai/common_utils.py uses Union at line 138 without importing it, which ruff check litellm reports as F821 on a clean checkout.

That is unrelated to this PR and I have deliberately left it out of scope, but CI here will stay red until it lands somewhere. Every number below was measured with that one import added to both the before and the after tree, identically, so it does not affect the comparison.

[Classic298]

@ishaan-berri

[Classic298]

Relates with: #35710

[codecov]

Codecov Report

❌ Patch coverage is 40.36958% with 839 lines in your changes missing coverage. Please review.

Files with missing lines	Patch %	Lines
litellm/proxy/_experimental/mcp_server/server.py	41.81%	32 Missing ⚠️
...oxy/_experimental/mcp_server/mcp_server_manager.py	62.06%	22 Missing ⚠️
litellm/integrations/prometheus.py	32.00%	17 Missing ⚠️
litellm/integrations/posthog.py	0.00%	15 Missing ⚠️
litellm/integrations/datadog/datadog_llm_obs.py	26.31%	14 Missing ⚠️
litellm/llms/github_copilot/authenticator.py	23.52%	13 Missing ⚠️
...itellm/integrations/azure_storage/azure_storage.py	25.00%	12 Missing ⚠️
litellm/llms/azure_ai/agents/handler.py	0.00%	12 Missing ⚠️
...s/claude_code_endpoints/claude_code_marketplace.py	7.69%	12 Missing ⚠️
...ardrail_hooks/zscaler_ai_guard/zscaler_ai_guard.py	0.00%	12 Missing ⚠️
... and 194 more

📢 Thoughts on this report? Let us know!

[Classic298]

that test coverage claim is bs - because 1) this doesnt need tests and 2) the test covers any addition of new bad logging calls

[Classic298]

@yuneng-berri since i saw you working on logging on another PR right now , you might find this interesting,.

[codspeed-hq]

Merging this PR will not alter performance

✅ 31 untouched benchmarks

---

_{Comparing Classic298:perf_lazy_debug_logging (be69229) with litellm_internal_staging (042ef4c)¹}

Footnotes

1. No successful run was found on litellm_internal_staging (2039981) during the generation of this report, so 042ef4c was used instead as the comparison base. There might be some changes unrelated to this pull request in this report. ↩

[yassin-berriai]

@greptileai please review the current head 35527fd

Rebased onto litellm_internal_staging at cb8c734, so the 5/5 above is pinned to a commit that is no longer in this PR. Two files conflicted and staging won both. litellm/integrations/rubrik.py had been refactored on staging, so staging's copy was taken wholesale and the rewrite re-applied to the 16 logging calls in it. litellm/proxy/litellm_pre_call_utils.py keeps staging's redact_credential_headers(_headers) call and defers only the interpolation, so that debug line still logs redacted headers. The other 407 files replayed unchanged

Worth pointing your review at two properties I checked mechanically and would like a second opinion on. Rendering every logging call on both sides with sentinel values, 4544 interpolating calls match on text, argument order, !r to %r conversion and keyword arguments with zero mismatches, and the 205 the checker cannot canonicalise are AST-identical to staging. Normalising every logging call to an opaque placeholder and diffing the ASTs leaves 409 of the 410 changed files identical to staging, the only exception being the test file

[CLAassistant]

Thank you for your submission! We really appreciate it. Like many open source projects, we ask that you all sign our Contributor License Agreement before we can accept your contribution.
1 out of 2 committers have signed the CLA.

✅ Classic298
❌ yassin-berriai
_{You have signed the CLA already but the status is still pending? Let us recheck it.}

[yassin-berriai]

@greptileai please review the current head be69229

The 5/5 above is anchored to 35527fd, which two rebases have since orphaned. Current state: rebased onto litellm_internal_staging at 2039981, and a second commit fixes the tests the rewrite broke. All 26 test, lint and code-quality checks are green; osv-scan fails on every open PR branch and this diff contains no dependency files, and codecov/patch is the usual late-converging one

Two things worth aiming your review at.

litellm/integrations/rubrik.py conflicted on both rebases because staging refactored it. Staging's copy was taken wholesale each time and the rewrite re-applied to its 16 logging calls, so please check that file against staging rather than against the previous revision of this PR

The second commit changes 17 assertions across 9 test files that read a mocked logger's call.args[0], which no longer holds the interpolated values. They now render the record the way logging does, so they hold under both the eager and the lazy form. One of them was a real hole rather than a cosmetic break: test_call_tool_does_not_log_arguments asserts MCP tool arguments are never logged, and reading args[0] alone had gone blind to a secret passed as a lazy argument. Leaking one deliberately, the old assertion passes while the secret is logged and the new one fails