fix(functions): avoid quadratic-time debug logging in CleanupLLMResult / ParseFunctionCall (#10592)

fix(functions): avoid quadratic-time debug logging in CleanupLLMResult/ParseFunctionCall

The streaming chat path (core/http/endpoints/openai/chat_stream_workers.go)
calls CleanupLLMResult / ParseFunctionCall once per delta chunk with the
*full accumulated* LLM result so far. Both functions xlog.Debug the entire
argument on entry and exit, so a single N-chunk stream emits roughly
chunk_size * N^2 bytes of debug output.

Under LOG_LEVEL=debug this was observed in a recent SGLang-via-LocalAI
session on a DGX Spark host (about 50K tokens, long streaming generation)
to drive container logs to ~96 GiB, which interacted with the streaming
hot loop on the same filesystem and contributed to a host-wide hard hang
once disk pressure built up. Workaround was setting LOG_LEVEL=info, but
the quadratic shape remains a foot-gun for anyone intentionally enabling
debug.

Replace the four result-content debug arguments with len(...) plus a
fixed-size head (200 bytes via a new truncForLog helper), bounding per-
call output to a constant. The debug signal stays useful: the first 200
chars are enough to identify which generation is in flight, and the
length lets you observe growth without paying for the payload itself.

No API change. No behaviour change for LOG_LEVEL != debug.

Signed-off-by: Poseidon <philipp.wacker@ibf-solutions.com>
Co-authored-by: Poseidon <philipp.wacker@ibf-solutions.com>
This commit is contained in:
pos-ei-don
2026-06-30 09:16:03 +02:00
committed by GitHub
parent 1a4f68ed4a
commit 2cee318fad

View File

@@ -252,8 +252,25 @@ func (g FunctionsConfig) GrammarOptions() []func(o *grammars.GrammarOption) {
return opts
}
// truncForLog returns a length+head-truncated view of s for debug logging.
//
// CleanupLLMResult / ParseFunctionCall are invoked once per streaming chunk
// with the *full accumulated* LLM result so far (see
// core/http/endpoints/openai/chat_stream_workers.go). Logging the full
// argument on every call gives O(N^2) total log volume across a single
// generation, which under LOG_LEVEL=debug has been observed to fill disks
// and stall the host during long streaming sessions. Logging only the
// length plus a fixed-size head bounds per-call output to a constant.
func truncForLog(s string) string {
const maxHead = 200
if len(s) <= maxHead {
return s
}
return s[:maxHead] + "...(truncated)"
}
func CleanupLLMResult(llmresult string, functionConfig FunctionsConfig) string {
xlog.Debug("LLM result", "result", llmresult)
xlog.Debug("LLM result", "len", len(llmresult), "head", truncForLog(llmresult))
for _, item := range functionConfig.ReplaceLLMResult {
k, v := item.Key, item.Value
@@ -261,7 +278,7 @@ func CleanupLLMResult(llmresult string, functionConfig FunctionsConfig) string {
re := regexp.MustCompile(k)
llmresult = re.ReplaceAllString(llmresult, v)
}
xlog.Debug("LLM result(processed)", "result", llmresult)
xlog.Debug("LLM result(processed)", "len", len(llmresult), "head", truncForLog(llmresult))
return llmresult
}
@@ -913,7 +930,7 @@ func parseParameterValue(paramValue string, format *XMLToolCallFormat) any {
func ParseFunctionCall(llmresult string, functionConfig FunctionsConfig) []FuncCallResults {
xlog.Debug("LLM result", "result", llmresult)
xlog.Debug("LLM result", "len", len(llmresult), "head", truncForLog(llmresult))
for _, item := range functionConfig.ReplaceFunctionResults {
k, v := item.Key, item.Value
@@ -921,7 +938,7 @@ func ParseFunctionCall(llmresult string, functionConfig FunctionsConfig) []FuncC
re := regexp.MustCompile(k)
llmresult = re.ReplaceAllString(llmresult, v)
}
xlog.Debug("LLM result(function cleanup)", "result", llmresult)
xlog.Debug("LLM result(function cleanup)", "len", len(llmresult), "head", truncForLog(llmresult))
functionNameKey := defaultFunctionNameKey
functionArgumentsKey := defaultFunctionArgumentsKey