GLOBAL_LOG_LEVEL defaults to INFO, so every log.debug(...) in the backend is discarded, but the message is built first: 187 call sites interpolate their payload into an f-string before the logging call runs, so the work happens on every request and the result is thrown away. The worst one sits in process_chat_payload and stringifies the whole request body, full conversation history included, once per chat completion.
That one line with DEBUG disabled, CPython 3.12:
| conversation | payload | before | after |
| ------------ | ------- | -------- | ------- |
| 4 messages | 1.2 kB | 3.4 us | 0.07 us |
| 20 messages | 17 kB | 24.8 us | 0.07 us |
| 60 messages | 123 kB | 216.6 us | 0.07 us |
The lazy form log.debug('form_data: %s', form_data) hands the payload to record.getMessage(), which the InterceptHandler only reaches once a record has passed the level check. With DEBUG enabled the emitted lines are byte-identical, f'{x=}' sites included: those map to %r. MistralLoader._debug_log callers get the same treatment, since that wrapper already forwards *args.
generate_function_chat_completion rewrote form_data['model'] to the base
model id in place. Because that dict is the same object process_chat_response
later re-submits for the post-tool-call continuation, the continuation was
access-checked against the base model instead of the user-facing preset.
For a public preset over a private/unregistered pipe base, a non-admin's
first message succeeded but the continuation after a native tool call was
denied and silently swallowed, aborting the response (admins skip the
user-only check, so they were unaffected).
Operate on a shallow copy of form_data, mirroring the openai/ollama routers
which already substitute the base model on a copy. The continuation now
re-checks the preset the user actually has access to.
Claude-Session: https://claude.ai/code/session_018toPfJW1hMXAhokGaL43Ep
Co-authored-by: Claude <noreply@anthropic.com>
