perf: avoid eager formatting in debug log calls (#4929)

This commit is contained in:
Seefs
2026-05-19 12:11:24 +08:00
committed by GitHub
parent 5dd0d3bcbd
commit 0936e25046
33 changed files with 110 additions and 149 deletions
+3 -4
View File
@@ -229,7 +229,7 @@ func asyncTaskWait(c *gin.Context, info *relaycommon.RelayInfo, taskID string) (
time.Sleep(time.Duration(5) * time.Second)
for {
logger.LogDebug(c, fmt.Sprintf("asyncTaskWait step %d/%d, wait %d seconds", step, maxStep, waitSeconds))
logger.LogDebug(c, "asyncTaskWait step %d/%d, wait %d seconds", step, maxStep, waitSeconds)
step++
rsp, err, body := updateTask(info, taskID)
responseBody = body
@@ -320,11 +320,10 @@ func aliImageHandler(a *Adaptor, c *gin.Context, resp *http.Response, info *rela
}
}
//logger.LogDebug(c, "ali_async_task_result: "+string(originRespBody))
if a.IsSyncImageModel {
logger.LogDebug(c, "ali_sync_image_result: "+string(originRespBody))
logger.LogDebug(c, "ali_sync_image_result: %s", originRespBody)
} else {
logger.LogDebug(c, "ali_async_image_result: "+string(originRespBody))
logger.LogDebug(c, "ali_async_image_result: %s", originRespBody)
}
imageResponses := responseAli2OpenAIImage(c, aliResponse, originRespBody, info, responseFormat)
+10 -30
View File
@@ -292,9 +292,7 @@ func DoApiRequest(a Adaptor, c *gin.Context, info *common.RelayInfo, requestBody
if err != nil {
return nil, fmt.Errorf("get request url failed: %w", err)
}
if common2.DebugEnabled {
println("fullRequestURL:", fullRequestURL)
}
logger.LogDebug(c, "fullRequestURL: %s", fullRequestURL)
req, err := http.NewRequest(c.Request.Method, fullRequestURL, requestBody)
if err != nil {
return nil, fmt.Errorf("new request failed: %w", err)
@@ -323,9 +321,7 @@ func DoFormRequest(a Adaptor, c *gin.Context, info *common.RelayInfo, requestBod
if err != nil {
return nil, fmt.Errorf("get request url failed: %w", err)
}
if common2.DebugEnabled {
println("fullRequestURL:", fullRequestURL)
}
logger.LogDebug(c, "fullRequestURL: %s", fullRequestURL)
req, err := http.NewRequest(c.Request.Method, fullRequestURL, requestBody)
if err != nil {
return nil, fmt.Errorf("new request failed: %w", err)
@@ -388,13 +384,9 @@ func startPingKeepAlive(c *gin.Context, pingInterval time.Duration) context.Canc
defer func() {
// 增加panic恢复处理
if r := recover(); r != nil {
if common2.DebugEnabled {
println("SSE ping goroutine panic recovered:", fmt.Sprintf("%v", r))
}
}
if common2.DebugEnabled {
println("SSE ping goroutine stopped.")
logger.LogDebug(c, "SSE ping goroutine panic recovered: %v", r)
}
logger.LogDebug(c, "SSE ping goroutine stopped")
}()
if pingInterval <= 0 {
@@ -405,15 +397,11 @@ func startPingKeepAlive(c *gin.Context, pingInterval time.Duration) context.Canc
// 确保在任何情况下都清理ticker
defer func() {
ticker.Stop()
if common2.DebugEnabled {
println("SSE ping ticker stopped")
}
logger.LogDebug(c, "SSE ping ticker stopped")
}()
var pingMutex sync.Mutex
if common2.DebugEnabled {
println("SSE ping goroutine started")
}
logger.LogDebug(c, "SSE ping goroutine started")
// 增加超时控制,防止goroutine长时间运行
maxPingDuration := 120 * time.Minute // 最大ping持续时间
@@ -425,9 +413,7 @@ func startPingKeepAlive(c *gin.Context, pingInterval time.Duration) context.Canc
// 发送 ping 数据
case <-ticker.C:
if err := sendPingData(c, &pingMutex); err != nil {
if common2.DebugEnabled {
println("SSE ping error, stopping goroutine:", err.Error())
}
logger.LogDebug(c, "SSE ping error, stopping goroutine: %s", err.Error())
return
}
// 收到退出信号
@@ -438,9 +424,7 @@ func startPingKeepAlive(c *gin.Context, pingInterval time.Duration) context.Canc
return
// 超时保护,防止goroutine无限运行
case <-pingTimeout.C:
if common2.DebugEnabled {
println("SSE ping goroutine timeout, stopping")
}
logger.LogDebug(c, "SSE ping goroutine timeout, stopping")
return
}
}
@@ -463,9 +447,7 @@ func sendPingData(c *gin.Context, mutex *sync.Mutex) error {
return
}
if common2.DebugEnabled {
println("SSE ping data sent.")
}
logger.LogDebug(c, "SSE ping data sent")
done <- nil
}()
@@ -507,9 +489,7 @@ func doRequest(c *gin.Context, req *http.Request, info *common.RelayInfo) (*http
defer func() {
if stopPinger != nil {
stopPinger()
if common2.DebugEnabled {
println("SSE ping goroutine stopped by defer")
}
logger.LogDebug(c, "SSE ping goroutine stopped by defer")
}
}()
}
+1 -3
View File
@@ -949,9 +949,7 @@ func ClaudeHandler(c *gin.Context, resp *http.Response, info *relaycommon.RelayI
if err != nil {
return nil, types.NewError(err, types.ErrorCodeBadResponseBody)
}
if common.DebugEnabled {
println("responseBody: ", string(responseBody))
}
logger.LogDebug(c, "responseBody: %s", responseBody)
handleErr := HandleClaudeResponseData(c, info, claudeInfo, resp, responseBody)
if handleErr != nil {
return nil, handleErr
+2 -6
View File
@@ -26,9 +26,7 @@ func GeminiTextGenerationHandler(c *gin.Context, info *relaycommon.RelayInfo, re
return nil, types.NewOpenAIError(err, types.ErrorCodeBadResponseBody, http.StatusInternalServerError)
}
if common.DebugEnabled {
println(string(responseBody))
}
logger.LogDebug(c, "Gemini native response body: %s", responseBody)
// 解析为 Gemini 原生响应格式
var geminiResponse dto.GeminiChatResponse
@@ -57,9 +55,7 @@ func NativeGeminiEmbeddingHandler(c *gin.Context, resp *http.Response, info *rel
return nil, types.NewOpenAIError(err, types.ErrorCodeBadResponseBody, http.StatusInternalServerError)
}
if common.DebugEnabled {
println(string(responseBody))
}
logger.LogDebug(c, "Gemini native embedding response body: %s", responseBody)
usage := service.ResponseText2Usage(c, "", info.UpstreamModelName, info.GetEstimatePromptTokens())
+2 -4
View File
@@ -1362,7 +1362,7 @@ func GeminiChatStreamHandler(c *gin.Context, info *relaycommon.RelayInfo, resp *
}
}
logger.LogDebug(c, fmt.Sprintf("info.SendResponseCount = %d", info.SendResponseCount))
logger.LogDebug(c, "info.SendResponseCount = %d", info.SendResponseCount)
if info.SendResponseCount == 0 {
// send first response
emptyResponse := helper.GenerateStartEmptyResponse(id, createAt, info.UpstreamModelName, nil)
@@ -1422,9 +1422,7 @@ func GeminiChatHandler(c *gin.Context, info *relaycommon.RelayInfo, resp *http.R
return nil, types.NewOpenAIError(err, types.ErrorCodeBadResponseBody, http.StatusInternalServerError)
}
service.CloseResponseBodyGracefully(resp)
if common.DebugEnabled {
println(string(responseBody))
}
logger.LogDebug(c, "Gemini response body: %s", responseBody)
var geminiResponse dto.GeminiChatResponse
err = common.Unmarshal(responseBody, &geminiResponse)
if err != nil {
+5 -5
View File
@@ -377,7 +377,7 @@ func (a *Adaptor) ConvertAudioRequest(c *gin.Context, info *relaycommon.RelayInf
}
// 打印类似 curl 命令格式的信息
logger.LogDebug(c.Request.Context(), fmt.Sprintf("--form 'model=\"%s\"'", request.Model))
logger.LogDebug(c.Request.Context(), "--form 'model=\"%s\"'", request.Model)
// 遍历表单字段并打印输出
for key, values := range formData.Value {
@@ -386,7 +386,7 @@ func (a *Adaptor) ConvertAudioRequest(c *gin.Context, info *relaycommon.RelayInf
}
for _, value := range values {
writer.WriteField(key, value)
logger.LogDebug(c.Request.Context(), fmt.Sprintf("--form '%s=\"%s\"'", key, value))
logger.LogDebug(c.Request.Context(), "--form '%s=\"%s\"'", key, value)
}
}
@@ -398,8 +398,8 @@ func (a *Adaptor) ConvertAudioRequest(c *gin.Context, info *relaycommon.RelayInf
// 使用 formData 中的第一个文件
fileHeader := fileHeaders[0]
logger.LogDebug(c.Request.Context(), fmt.Sprintf("--form 'file=@\"%s\"' (size: %d bytes, content-type: %s)",
fileHeader.Filename, fileHeader.Size, fileHeader.Header.Get("Content-Type")))
logger.LogDebug(c.Request.Context(), "--form 'file=@\"%s\"' (size: %d bytes, content-type: %s)",
fileHeader.Filename, fileHeader.Size, fileHeader.Header.Get("Content-Type"))
file, err := fileHeader.Open()
if err != nil {
@@ -418,7 +418,7 @@ func (a *Adaptor) ConvertAudioRequest(c *gin.Context, info *relaycommon.RelayInf
// 关闭 multipart 编写器以设置分界线
writer.Close()
c.Request.Header.Set("Content-Type", writer.FormDataContentType())
logger.LogDebug(c.Request.Context(), fmt.Sprintf("--header 'Content-Type: %s'", writer.FormDataContentType()))
logger.LogDebug(c.Request.Context(), "--header 'Content-Type: %s'", writer.FormDataContentType())
return &requestBody, nil
}
}
+3 -5
View File
@@ -155,9 +155,9 @@ func OaiStreamHandler(c *gin.Context, info *relaycommon.RelayInfo, resp *http.Re
containStreamUsage = true
if common.DebugEnabled {
logger.LogDebug(c, fmt.Sprintf("Audio model usage extracted from second last SSE: PromptTokens=%d, CompletionTokens=%d, TotalTokens=%d, InputTokens=%d, OutputTokens=%d",
logger.LogDebug(c, "Audio model usage extracted from second last SSE: PromptTokens=%d, CompletionTokens=%d, TotalTokens=%d, InputTokens=%d, OutputTokens=%d",
usage.PromptTokens, usage.CompletionTokens, usage.TotalTokens,
usage.InputTokens, usage.OutputTokens))
usage.InputTokens, usage.OutputTokens)
}
}
}
@@ -200,9 +200,7 @@ func OpenaiHandler(c *gin.Context, info *relaycommon.RelayInfo, resp *http.Respo
if err != nil {
return nil, types.NewOpenAIError(err, types.ErrorCodeReadResponseBodyFailed, http.StatusInternalServerError)
}
if common.DebugEnabled {
println("upstream response body:", string(responseBody))
}
logger.LogDebug(c, "upstream response body: %s", responseBody)
// Unmarshal to simpleResponse
if info.ChannelType == constant.ChannelTypeOpenRouter && info.ChannelOtherSettings.IsOpenRouterEnterprise() {
// 尝试解析为 openrouter enterprise