From c690448f0786aef0a6ad7e9f4712a8eab6c4fac0 Mon Sep 17 00:00:00 2001 From: Poseidon Date: Mon, 29 Jun 2026 19:19:12 +0200 Subject: [PATCH] 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 --- pkg/functions/parse.go | 25 +++++++++++++++++++++---- 1 file changed, 21 insertions(+), 4 deletions(-) diff --git a/pkg/functions/parse.go b/pkg/functions/parse.go index d6be3b0f551e..c5dc4d406c7b 100644 --- a/pkg/functions/parse.go +++ b/pkg/functions/parse.go @@ -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