feat(logger): implement LLM debug logging functionality

- Added a new logger for LLM calls, enabling detailed logging of model interactions, including request and response data.
- Introduced configuration options for enabling and specifying the log directory for LLM debug logs.
- Implemented cleanup for old log files to manage disk space effectively.
- Wrapped existing chat implementations to log calls when debug logging is enabled, enhancing traceability for model interactions.
This commit is contained in:
wizardchen
2026-04-16 22:39:10 +08:00
committed by lyingbug
parent 6235a82183
commit 53e8e17df4
22 changed files with 1304 additions and 265 deletions
+4
View File
@@ -14,6 +14,10 @@ GIN_MODE=release
# 日志级别,可选值:debug, info, warn, error, fatal,默认为debug
# LOG_LEVEL=debug
# LLM 调试日志:将每次大模型调用的完整请求和响应写入独立日志文件,便于排查上下文问题
# 可选值:true(自动放在 LOG_PATH 同目录下 llm_debug.log)、false/空(关闭)、或指定文件路径
# LLM_DEBUG_LOG=true
# 时区设置,默认为 Asia/Shanghai
# 影响系统时间显示和日志时间戳
# 常用值:Asia/Shanghai, Asia/Tokyo, America/New_York, Europe/London, UTC
+16 -7
View File
@@ -29,14 +29,23 @@ func (r *chunkRepository) CreateChunks(ctx context.Context, chunks []*types.Chun
for _, chunk := range chunks {
chunk.Content = common.CleanInvalidUTF8(chunk.Content)
}
// Pre-assign SeqIDs for SQLite compatibility (autoIncrement on non-PK columns
// doesn't work in SQLite). This is a no-op if all chunks already have SeqIDs.
if err := types.AssignChunkSeqIDs(r.db.WithContext(ctx), chunks); err != nil {
return fmt.Errorf("failed to assign chunk seq_ids: %w", err)
db := r.db.WithContext(ctx)
// SQLite doesn't support autoIncrement on non-PK columns,
// so we must pre-assign SeqIDs manually (safe: single connection).
// PostgreSQL / MySQL use DB sequences — skip to avoid duplicate key
// races under concurrent inserts.
if db.Dialector.Name() == "sqlite" {
if err := types.AssignChunkSeqIDs(db, chunks); err != nil {
return fmt.Errorf("failed to assign chunk seq_ids: %w", err)
}
}
// Use Select("*") to ensure all fields including zero values (IsEnabled=false, Flags=0)
// are inserted, bypassing GORM's default value behavior for zero values
return r.db.WithContext(ctx).Select("*").CreateInBatches(chunks, 100).Error
// Select("*") ensures zero-value fields (IsEnabled=false, Flags=0) are
// explicitly inserted, bypassing GORM's default value behavior.
// SeqID=0 is skipped by GORM automatically (autoIncrement tag).
return db.Select("*").CreateInBatches(chunks, 100).Error
}
// GetChunkByID retrieves a chunk by its ID and tenant ID
@@ -133,37 +133,32 @@ func (p *PluginIntoChatMessage) OnEvent(ctx context.Context,
// Build contexts string based on FAQ priority strategy
if chatManage.FAQPriorityEnabled && len(faqResults) > 0 {
// Build structured context with FAQ prioritization
contextsBuilder.WriteString("### Source 1: FAQ Knowledge Base\n")
contextsBuilder.WriteString("[High Confidence - Prioritize these results]\n")
contextsBuilder.WriteString("<source type=\"faq\" priority=\"high\">\n")
for i, result := range faqResults {
passage := getEnrichedPassageForChat(ctx, result)
if hasHighConfidenceFAQ && i == 0 {
contextsBuilder.WriteString(fmt.Sprintf("[FAQ-%d] Exact Match: %s\n", i+1, passage))
contextsBuilder.WriteString(fmt.Sprintf("<context id=\"FAQ-%d\" match=\"exact\">%s</context>\n", i+1, passage))
} else {
contextsBuilder.WriteString(fmt.Sprintf("[FAQ-%d] %s\n", i+1, passage))
contextsBuilder.WriteString(fmt.Sprintf("<context id=\"FAQ-%d\">%s</context>\n", i+1, passage))
}
}
contextsBuilder.WriteString("</source>\n")
if len(docResults) > 0 {
contextsBuilder.WriteString("\n### Source 2: Reference Documents\n")
contextsBuilder.WriteString("[Supplementary - Use only when FAQ cannot answer the question]\n")
contextsBuilder.WriteString("<source type=\"document\" priority=\"supplementary\">\n")
for i, result := range docResults {
passage := getEnrichedPassageForChat(ctx, result)
contextsBuilder.WriteString(fmt.Sprintf("[DOC-%d] %s\n", i+1, passage))
contextsBuilder.WriteString(fmt.Sprintf("<context id=\"DOC-%d\">%s</context>\n", i+1, passage))
}
contextsBuilder.WriteString("</source>")
}
} else {
// Original behavior: simple numbered list
passages := make([]string, len(chatManage.MergeResult))
for i, result := range chatManage.MergeResult {
passages[i] = getEnrichedPassageForChat(ctx, result)
}
for i, passage := range passages {
passage := getEnrichedPassageForChat(ctx, result)
if i > 0 {
contextsBuilder.WriteString("\n\n")
contextsBuilder.WriteString("\n")
}
contextsBuilder.WriteString(fmt.Sprintf("[%d] %s", i+1, passage))
contextsBuilder.WriteString(fmt.Sprintf("<context id=\"%d\">%s</context>", i+1, passage))
}
}
@@ -279,15 +274,16 @@ func buildDocumentHeader(results []*types.SearchResult) string {
}
var b strings.Builder
b.WriteString("### Referenced Documents\n")
for i, d := range docs {
// if d.description != "" {
// b.WriteString(fmt.Sprintf("%d. %s — %s\n", i+1, d.title, d.description))
// } else {
// b.WriteString(fmt.Sprintf("%d. %s\n", i+1, d.title))
// }
b.WriteString(fmt.Sprintf("%d. %s\n", i+1, d.title))
b.WriteString("<documents>\n")
for _, d := range docs {
b.WriteString("<document>\n")
b.WriteString(fmt.Sprintf("<title>%s</title>\n", d.title))
if d.description != "" {
b.WriteString(fmt.Sprintf("<description>%s</description>\n", d.description))
}
b.WriteString("</document>\n")
}
b.WriteString("</documents>")
return b.String()
}
@@ -310,105 +306,101 @@ func getEnrichedPassageForChat(ctx context.Context, result *types.SearchResult)
// 正则表达式用于匹配Markdown图片链接
var markdownImageRegex = regexp.MustCompile(`!\[([^\]]*)\]\(([^)]+)\)`)
// enrichContentWithImageInfo 将图片信息文本内容合并
// enrichContentWithImageInfo 将图片信息以 XML 标签的形式嵌入文本内容
// 对于内容中已有的 Markdown 图片链接,在其后附加 <image_caption> / <image_ocr>
// 对于未出现在内容中的图片,以 <image> 块追加到末尾。
func enrichContentWithImageInfo(ctx context.Context, content string, imageInfoJSON string) string {
// 解析ImageInfo
var imageInfos []types.ImageInfo
err := json.Unmarshal([]byte(imageInfoJSON), &imageInfos)
if err != nil {
if err := json.Unmarshal([]byte(imageInfoJSON), &imageInfos); err != nil {
pipelineWarn(ctx, "IntoChatMessage", "image_parse_error", map[string]interface{}{
"error": err.Error(),
})
return content
}
if len(imageInfos) == 0 {
return content
}
// 创建图片URL到信息的映射
imageInfoMap := make(map[string]*types.ImageInfo)
for i := range imageInfos {
if imageInfos[i].URL != "" {
imageInfoMap[imageInfos[i].URL] = &imageInfos[i]
}
// 同时检查原始URL
if imageInfos[i].OriginalURL != "" {
imageInfoMap[imageInfos[i].OriginalURL] = &imageInfos[i]
}
}
// 查找内容中的所有Markdown图片链接
matches := markdownImageRegex.FindAllStringSubmatch(content, -1)
// 用于存储已处理的图片URL
processedURLs := make(map[string]bool)
pipelineInfo(ctx, "IntoChatMessage", "image_markdown_links", map[string]interface{}{
"match_count": len(matches),
})
// 替换每个图片链接,添加描述和OCR文本
for _, match := range matches {
if len(match) < 3 {
continue
}
// 提取图片URL,忽略alt文本
imgURL := match[2]
// 标记该URL已处理
processedURLs[imgURL] = true
// 查找匹配的图片信息
imgInfo, found := imageInfoMap[imgURL]
// 如果找到匹配的图片信息,添加描述和OCR文本
var b strings.Builder
b.WriteString(fmt.Sprintf("<image url=\"%s\">\n", imgURL))
b.WriteString(fmt.Sprintf("<image_original>%s</image_original>\n", match[0]))
if found && imgInfo != nil {
replacement := match[0] + "\n"
if imgInfo.Caption != "" {
replacement += fmt.Sprintf("Image Caption: %s\n", imgInfo.Caption)
}
if imgInfo.OCRText != "" {
replacement += fmt.Sprintf("Image Text: %s\n", imgInfo.OCRText)
}
content = strings.Replace(content, match[0], replacement, 1)
b.WriteString(buildImageInfoXML(imgInfo))
}
b.WriteString("</image>")
content = strings.Replace(content, match[0], b.String(), 1)
}
// 处理未在内容中找到但存在于ImageInfo中的图片
var additionalImageTexts []string
// Append image info not found as inline Markdown links
var extras []string
for _, imgInfo := range imageInfos {
// 如果图片URL已经处理过,跳过
if processedURLs[imgInfo.URL] || processedURLs[imgInfo.OriginalURL] {
continue
}
var imgTexts []string
if imgInfo.Caption != "" {
imgTexts = append(imgTexts, fmt.Sprintf("Image %s caption: %s", imgInfo.URL, imgInfo.Caption))
url := imgInfo.URL
if url == "" {
url = imgInfo.OriginalURL
}
if imgInfo.OCRText != "" {
imgTexts = append(imgTexts, fmt.Sprintf("Image %s text: %s", imgInfo.URL, imgInfo.OCRText))
}
if len(imgTexts) > 0 {
additionalImageTexts = append(additionalImageTexts, imgTexts...)
if block := buildImageInfoXMLWithURL(url, &imgInfo); block != "" {
extras = append(extras, block)
}
}
// 如果有额外的图片信息,添加到内容末尾
if len(additionalImageTexts) > 0 {
if len(extras) > 0 {
if content != "" {
content += "\n\n"
content += "\n"
}
content += "Additional Image Info:\n" + strings.Join(additionalImageTexts, "\n")
content += strings.Join(extras, "\n")
}
pipelineInfo(ctx, "IntoChatMessage", "image_enrich_summary", map[string]interface{}{
"markdown_images": len(matches),
"additional_imgs": len(additionalImageTexts),
"additional_imgs": len(extras),
})
return content
}
// buildImageInfoXML returns XML-tagged caption / ocr for one image.
func buildImageInfoXML(img *types.ImageInfo) string {
var b strings.Builder
if img.Caption != "" {
b.WriteString(fmt.Sprintf("<image_caption>%s</image_caption>\n", img.Caption))
}
if img.OCRText != "" {
b.WriteString(fmt.Sprintf("<image_ocr>%s</image_ocr>\n", img.OCRText))
}
return b.String()
}
// buildImageInfoXMLWithURL wraps image info in an <image> element carrying the URL.
func buildImageInfoXMLWithURL(url string, img *types.ImageInfo) string {
inner := buildImageInfoXML(img)
if inner == "" {
return ""
}
return fmt.Sprintf("<image url=\"%s\">\n%s</image>", url, inner)
}
@@ -260,136 +260,207 @@ func (p *PluginMerge) resolveParentChunks(
parentMap[c.ID] = c
}
// Check if any results are image chunks; only then do we need
// grandparent resolution and the extra DB round-trip.
hasImageResults := false
for _, r := range results {
if r.ChunkType == string(types.ChunkTypeImageOCR) || r.ChunkType == string(types.ChunkTypeImageCaption) {
hasImageResults = true
break
}
}
var grandparentIDs []string
if hasImageResults {
// Fetch grandparent chunks for the image → text → parent_text chain.
for _, pc := range parentChunks {
if pc.ParentChunkID != "" && pc.ChunkType == types.ChunkTypeText {
if _, already := parentMap[pc.ParentChunkID]; !already {
grandparentIDs = append(grandparentIDs, pc.ParentChunkID)
}
}
}
if len(grandparentIDs) > 0 {
gpChunks, err := p.chunkRepo.ListChunksByID(ctx, tenantID, grandparentIDs)
if err != nil {
pipelineWarn(ctx, "Merge", "grandparent_fetch_failed", map[string]interface{}{
"error": err.Error(),
})
} else {
for _, c := range gpChunks {
parentMap[c.ID] = c
}
}
}
}
// Collect merged ImageInfo for each parent by fetching ALL sibling
// child chunks. Individual child chunks only carry ImageInfo for images
// within their own range, but the parent content spans all children.
parentImageInfoMap := p.collectParentImageInfo(ctx, tenantID, ids)
imageInfoIDs := ids
if len(grandparentIDs) > 0 {
imageInfoIDs = append(append([]string(nil), ids...), grandparentIDs...)
}
parentImageInfoMap := p.collectParentImageInfo(ctx, tenantID, imageInfoIDs)
// Replace child content with parent content.
// Only replace for text chunks whose parent is a parent_text chunk
// (i.e., the parent-child chunking strategy). Summary chunks also carry
// a ParentChunkID that points to their source chunk, but that is a
// different semantic — replacing summary content with its source would
// degrade quality.
for _, r := range results {
if r.ParentChunkID == "" {
continue
}
// Skip non-text chunks (e.g., summary, image_caption) — their
// ParentChunkID has a different meaning than the parent-child
// chunking strategy.
if r.ChunkType != string(types.ChunkTypeText) {
continue
}
parent, ok := parentMap[r.ParentChunkID]
if !ok || parent.Content == "" {
continue
}
// Only replace if the parent is actually a parent_text chunk from
// the parent-child chunking strategy.
if parent.ChunkType != types.ChunkTypeParentText {
continue
}
pipelineInfo(ctx, "Merge", "parent_resolve", map[string]interface{}{
"child_id": r.ID,
"parent_id": r.ParentChunkID,
"child_len": runeLen(r.Content),
"parent_len": runeLen(parent.Content),
})
r.Content = parent.Content
r.StartAt = parent.StartAt
r.EndAt = parent.EndAt
if mergedImageInfo, ok := parentImageInfoMap[r.ParentChunkID]; ok && mergedImageInfo != "" {
r.ImageInfo = mergedImageInfo
}
// Track the original child as a sub-chunk
if !containsID(r.SubChunkID, r.ID) {
r.SubChunkID = append(r.SubChunkID, r.ID)
switch r.ChunkType {
case string(types.ChunkTypeText):
// text → parent_text resolution (parent-child chunking strategy).
// Summary chunks also carry a ParentChunkID that points to their
// source chunk, but that is a different semantic — replacing
// summary content with its source would degrade quality.
parent, ok := parentMap[r.ParentChunkID]
if !ok || parent.Content == "" || parent.ChunkType != types.ChunkTypeParentText {
continue
}
pipelineInfo(ctx, "Merge", "parent_resolve", map[string]interface{}{
"child_id": r.ID,
"parent_id": r.ParentChunkID,
"child_len": runeLen(r.Content),
"parent_len": runeLen(parent.Content),
})
r.Content = parent.Content
r.StartAt = parent.StartAt
r.EndAt = parent.EndAt
if mergedImageInfo, ok := parentImageInfoMap[r.ParentChunkID]; ok && mergedImageInfo != "" {
r.ImageInfo = mergedImageInfo
}
if !containsID(r.SubChunkID, r.ID) {
r.SubChunkID = append(r.SubChunkID, r.ID)
}
case string(types.ChunkTypeImageOCR), string(types.ChunkTypeImageCaption):
// image_ocr/image_caption → text parent → optional parent_text grandparent.
// Replace content with parent text for surrounding context.
parent, ok := parentMap[r.ParentChunkID]
if !ok || parent.Content == "" {
continue
}
resolvedParent := parent
// If parent text uses parent-child chunking, resolve one more level
if parent.ChunkType == types.ChunkTypeText && parent.ParentChunkID != "" {
if gp, gpOK := parentMap[parent.ParentChunkID]; gpOK && gp.ChunkType == types.ChunkTypeParentText && gp.Content != "" {
resolvedParent = gp
}
}
pipelineInfo(ctx, "Merge", "image_parent_resolve", map[string]interface{}{
"child_id": r.ID,
"child_type": r.ChunkType,
"resolved_id": resolvedParent.ID,
"child_len": runeLen(r.Content),
"parent_len": runeLen(resolvedParent.Content),
})
r.Content = resolvedParent.Content
r.StartAt = resolvedParent.StartAt
r.EndAt = resolvedParent.EndAt
if mergedInfo, ok := parentImageInfoMap[resolvedParent.ID]; ok && mergedInfo != "" {
r.ImageInfo = mergedInfo
}
if !containsID(r.SubChunkID, r.ID) {
r.SubChunkID = append(r.SubChunkID, r.ID)
}
}
}
return results
}
// collectParentImageInfo batch-fetches all child chunks for the given parents
// and merges their ImageInfo into a single JSON string per parent. This ensures
// that when child content is replaced with parent content, the complete set of
// image descriptions across all sibling chunks is preserved.
// collectParentImageInfo batch-fetches image info for the given parent_text
// chunk IDs using a two-level query:
//
// Level 1: parent_text → text children
// Level 2: text children → image_ocr / image_caption grandchildren (carry image_info)
func (p *PluginMerge) collectParentImageInfo(
ctx context.Context,
tenantID uint64,
parentIDs []string,
) map[string]string {
result := make(map[string]string, len(parentIDs))
allChildren, err := p.chunkRepo.ListChunksByParentIDs(ctx, tenantID, parentIDs)
// Level 1: get direct children of parent_text chunks
children, err := p.chunkRepo.ListChunksByParentIDs(ctx, tenantID, parentIDs)
if err != nil {
pipelineWarn(ctx, "Merge", "parent_imageinfo_fetch_failed", map[string]interface{}{
"parent_cnt": len(parentIDs),
"error": err.Error(),
})
return result
return nil
}
// Group children by parent chunk ID, collecting unique ImageInfo entries
type parentAgg struct {
imageInfos []types.ImageInfo
uniqueURLs map[string]bool
siblingCnt int
type agg struct {
infos []types.ImageInfo
seenURLs map[string]bool
}
aggMap := make(map[string]*parentAgg, len(parentIDs))
for _, child := range allChildren {
agg, ok := aggMap[child.ParentChunkID]
if !ok {
agg = &parentAgg{uniqueURLs: make(map[string]bool)}
aggMap[child.ParentChunkID] = agg
}
agg.siblingCnt++
if child.ImageInfo == "" {
continue
aggMap := make(map[string]*agg)
addInfo := func(targetID string, chunk *types.Chunk) {
if chunk.ImageInfo == "" {
return
}
var infos []types.ImageInfo
if err := json.Unmarshal([]byte(child.ImageInfo), &infos); err != nil {
pipelineWarn(ctx, "Merge", "parent_imageinfo_parse", map[string]interface{}{
"chunk_id": child.ID,
"error": err.Error(),
})
continue
if err := json.Unmarshal([]byte(chunk.ImageInfo), &infos); err != nil || len(infos) == 0 {
return
}
a, ok := aggMap[targetID]
if !ok {
a = &agg{seenURLs: make(map[string]bool)}
aggMap[targetID] = a
}
for _, info := range infos {
key := info.URL
if key == "" {
key = info.OriginalURL
}
if key != "" && !agg.uniqueURLs[key] {
agg.uniqueURLs[key] = true
agg.imageInfos = append(agg.imageInfos, info)
if key != "" && !a.seenURLs[key] {
a.seenURLs[key] = true
a.infos = append(a.infos, info)
}
}
}
for parentID, agg := range aggMap {
if len(agg.imageInfos) == 0 {
continue
var textChildIDs []string
textToParent := make(map[string]string, len(children))
for _, child := range children {
switch child.ChunkType {
case types.ChunkTypeImageOCR, types.ChunkTypeImageCaption:
addInfo(child.ParentChunkID, child)
case types.ChunkTypeText:
textChildIDs = append(textChildIDs, child.ID)
textToParent[child.ID] = child.ParentChunkID
}
merged, err := json.Marshal(agg.imageInfos)
if err != nil {
pipelineWarn(ctx, "Merge", "parent_imageinfo_marshal", map[string]interface{}{
"parent_id": parentID,
"error": err.Error(),
})
continue
}
result[parentID] = string(merged)
pipelineInfo(ctx, "Merge", "parent_imageinfo_collected", map[string]interface{}{
"parent_id": parentID,
"sibling_cnt": agg.siblingCnt,
"image_cnt": len(agg.imageInfos),
})
}
// Level 2: text children → image grandchildren
if len(textChildIDs) > 0 {
grandChildren, err := p.chunkRepo.ListChunksByParentIDs(ctx, tenantID, textChildIDs)
if err != nil {
pipelineWarn(ctx, "Merge", "parent_imageinfo_l2_fetch_failed", map[string]interface{}{
"text_cnt": len(textChildIDs),
"error": err.Error(),
})
} else {
for _, gc := range grandChildren {
if gc.ChunkType != types.ChunkTypeImageOCR && gc.ChunkType != types.ChunkTypeImageCaption {
continue
}
if parentTextID, ok := textToParent[gc.ParentChunkID]; ok {
addInfo(parentTextID, gc)
}
}
}
}
result := make(map[string]string, len(aggMap))
for id, a := range aggMap {
if len(a.infos) == 0 {
continue
}
data, err := json.Marshal(a.infos)
if err == nil {
result[id] = string(data)
}
}
return result
}
@@ -611,6 +611,8 @@ func (p *PluginSearch) tryDirectChunkLoading(ctx context.Context, tenantID uint6
results = append(results, res)
}
searchutil.EnrichSearchResultsImageInfo(ctx, p.chunkService.GetRepository(), tenantID, results)
return results, skippedIDs
}
@@ -5,6 +5,7 @@ import (
"sync"
"github.com/Tencent/WeKnora/internal/logger"
"github.com/Tencent/WeKnora/internal/searchutil"
"github.com/Tencent/WeKnora/internal/types"
"github.com/Tencent/WeKnora/internal/types/interfaces"
)
@@ -161,10 +162,13 @@ func (p *PluginSearchEntity) OnEvent(ctx context.Context,
for _, knowledge := range knowledges {
knowledgeMap[knowledge.ID] = knowledge
}
var entityResults []*types.SearchResult
for _, chunk := range chunks {
searchResult := chunk2SearchResult(chunk, knowledgeMap[chunk.KnowledgeID])
chatManage.SearchResult = append(chatManage.SearchResult, searchResult)
entityResults = append(entityResults, searchResult)
}
searchutil.EnrichSearchResultsImageInfo(ctx, p.chunkRepo, types.MustTenantIDFromContext(ctx), entityResults)
chatManage.SearchResult = append(chatManage.SearchResult, entityResults...)
// remove duplicate results
chatManage.SearchResult = removeDuplicateResults(chatManage.SearchResult)
if len(chatManage.SearchResult) == 0 {
@@ -172,13 +172,11 @@ func (s *ImageMultimodalService) Handle(ctx context.Context, task *asynq.Task) e
}
}
if payload.EnableCaption {
caption, capErr := vlmModel.Predict(ctx, [][]byte{imgBytes}, vlmCaptionPrompt)
if capErr != nil {
logger.Warnf(ctx, "[ImageMultimodal] Caption failed for %s: %v", payload.ImageURL, capErr)
} else if caption != "" {
imageInfo.Caption = caption
}
caption, capErr := vlmModel.Predict(ctx, [][]byte{imgBytes}, vlmCaptionPrompt)
if capErr != nil {
logger.Warnf(ctx, "[ImageMultimodal] Caption failed for %s: %v", payload.ImageURL, capErr)
} else if caption != "" {
imageInfo.Caption = caption
}
// Build child chunks for OCR and caption results
@@ -220,8 +218,6 @@ func (s *ImageMultimodalService) Handle(ctx context.Context, task *asynq.Task) e
}
if len(newChunks) == 0 {
// Even if OCR/caption both failed, mark knowledge as completed
s.finalizeImageKnowledge(ctx, payload, "")
s.checkAndFinalizeAllImages(ctx, payload)
return nil
}
@@ -238,13 +234,6 @@ func (s *ImageMultimodalService) Handle(ctx context.Context, task *asynq.Task) e
// Index chunks so they can be retrieved
s.indexChunks(ctx, payload, newChunks)
// Update the parent text chunk's ImageInfo (mirrors old docreader behaviour)
s.updateParentChunkImageInfo(ctx, payload, imageInfo)
// For standalone image files, use caption as the knowledge description
// and mark the knowledge as completed (it was kept in "processing" until now).
s.finalizeImageKnowledge(ctx, payload, imageInfo.Caption)
// Enqueue question generation for the caption/OCR content if KB has it enabled.
// During initial processChunks, question generation is skipped for image-type
// knowledge because the text chunk is just a markdown reference. Now that we
@@ -256,36 +245,6 @@ func (s *ImageMultimodalService) Handle(ctx context.Context, task *asynq.Task) e
return nil
}
// finalizeImageKnowledge updates the knowledge after multimodal processing:
// - For standalone image files: sets Description from caption and marks ParseStatus as completed
// (processChunks kept it in "processing" to wait for multimodal results).
// - For images extracted from PDFs: no-op (description comes from summary generation).
func (s *ImageMultimodalService) finalizeImageKnowledge(ctx context.Context, payload types.ImageMultimodalPayload, caption string) {
knowledge, err := s.knowledgeRepo.GetKnowledgeByIDOnly(ctx, payload.KnowledgeID)
if err != nil {
logger.Warnf(ctx, "[ImageMultimodal] Failed to get knowledge %s: %v", payload.KnowledgeID, err)
return
}
if knowledge == nil {
return
}
if !IsImageType(knowledge.FileType) {
return
}
if caption != "" {
knowledge.Description = caption
}
knowledge.ParseStatus = types.ParseStatusCompleted
knowledge.UpdatedAt = time.Now()
if err := s.knowledgeRepo.UpdateKnowledge(ctx, knowledge); err != nil {
logger.Warnf(ctx, "[ImageMultimodal] Failed to finalize knowledge: %v", err)
} else {
logger.Infof(ctx, "[ImageMultimodal] Finalized image knowledge %s (status=completed, description=%d chars)",
payload.KnowledgeID, len(knowledge.Description))
}
}
// indexChunks indexes the newly created multimodal chunks into the retrieval engine
// so they can participate in semantic search.
func (s *ImageMultimodalService) indexChunks(ctx context.Context, payload types.ImageMultimodalPayload, chunks []*types.Chunk) {
@@ -348,47 +307,6 @@ func (s *ImageMultimodalService) indexChunks(ctx context.Context, payload types.
logger.Infof(ctx, "[ImageMultimodal] Indexed %d multimodal chunks for image %s", len(chunks), payload.ImageURL)
}
// updateParentChunkImageInfo updates the parent text chunk's ImageInfo field,
// replicating the behaviour of the old docreader flow where the parent chunk
// carried the full image metadata (URL, OCR, caption).
func (s *ImageMultimodalService) updateParentChunkImageInfo(ctx context.Context, payload types.ImageMultimodalPayload, imageInfo types.ImageInfo) {
if payload.ChunkID == "" {
return
}
chunk, err := s.chunkService.GetChunkByIDOnly(ctx, payload.ChunkID)
if err != nil {
logger.Warnf(ctx, "[ImageMultimodal] Failed to get parent chunk %s: %v", payload.ChunkID, err)
return
}
var existingInfos []types.ImageInfo
if chunk.ImageInfo != "" {
_ = json.Unmarshal([]byte(chunk.ImageInfo), &existingInfos)
}
found := false
for i, info := range existingInfos {
if info.URL == imageInfo.URL {
existingInfos[i] = imageInfo
found = true
break
}
}
if !found {
existingInfos = append(existingInfos, imageInfo)
}
imageInfoJSON, _ := json.Marshal(existingInfos)
chunk.ImageInfo = string(imageInfoJSON)
chunk.UpdatedAt = time.Now()
if err := s.chunkService.UpdateChunk(ctx, chunk); err != nil {
logger.Warnf(ctx, "[ImageMultimodal] Failed to update parent chunk %s ImageInfo: %v", chunk.ID, err)
} else {
logger.Infof(ctx, "[ImageMultimodal] Updated parent chunk %s ImageInfo for image %s", chunk.ID, payload.ImageURL)
}
}
// resolveVLM creates a vlm.VLM instance for the given knowledge base,
// supporting both new-style (ModelID) and legacy (inline BaseURL) configs.
func (s *ImageMultimodalService) resolveVLM(ctx context.Context, kbID string) (vlm.VLM, error) {
@@ -464,7 +382,6 @@ func (s *ImageMultimodalService) checkAndFinalizeAllImages(ctx context.Context,
logger.Infof(ctx, "[ImageMultimodal] All images processed for knowledge %s. Finalizing...", payload.KnowledgeID)
s.redisClient.Del(ctx, redisKey)
// Enqueue the post process task to handle all downstream tasks (summary, question generation, etc)
s.enqueueKnowledgePostProcessTask(ctx, payload)
}
}
@@ -6,6 +6,7 @@ import (
"slices"
"github.com/Tencent/WeKnora/internal/logger"
"github.com/Tencent/WeKnora/internal/searchutil"
"github.com/Tencent/WeKnora/internal/types"
)
@@ -59,12 +60,32 @@ func (s *knowledgeBaseService) processSearchResults(ctx context.Context,
for _, chunk := range additionalChunks {
chunkMap[chunk.ID] = chunk
}
// Second round: only needed when image chunks are among primary
// results (image → text resolved above, now text → parent_text).
// For normal text-only results this is a no-op.
if s.hasImageChunks(allChunks) {
parentIDs := s.collectParentChunkIDs(additionalChunks, index)
if len(parentIDs) > 0 {
logger.Infof(ctx, "Fetching %d second-level parent chunks", len(parentIDs))
parentChunks, err := s.listChunksByIDWithShared(ctx, tenantID, parentIDs)
if err != nil {
logger.Warnf(ctx, "Failed to fetch second-level parent chunks: %v", err)
} else {
for _, chunk := range parentChunks {
chunkMap[chunk.ID] = chunk
}
}
}
}
}
}
}
// Build final search results
searchResults := s.assembleSearchResults(ctx, chunks, chunkMap, knowledgeMap, index, skipEnrichment)
searchutil.EnrichSearchResultsImageInfo(ctx, s.chunkRepo, tenantID, searchResults)
logger.Infof(ctx, "Search results processed, total: %d", len(searchResults))
return searchResults, nil
}
@@ -151,6 +172,36 @@ func (s *knowledgeBaseService) collectEnrichmentChunkIDs(
return additionalIDs
}
// collectParentChunkIDs returns unprocessed parent IDs from the given chunks.
// Unlike collectEnrichmentChunkIDs, this only resolves parent links without
// expanding nearby or related chunks, making it suitable for second-round
// parent chain resolution (e.g., text → parent_text after image → text).
func (s *knowledgeBaseService) collectParentChunkIDs(
chunks []*types.Chunk,
idx *chunkIndex,
) []string {
var ids []string
for _, chunk := range chunks {
if chunk.ParentChunkID != "" && !idx.processedIDs[chunk.ParentChunkID] {
ids = append(ids, chunk.ParentChunkID)
idx.processedIDs[chunk.ParentChunkID] = true
idx.scores[chunk.ParentChunkID] = idx.scores[chunk.ID]
idx.matchTypes[chunk.ParentChunkID] = types.MatchTypeParentChunk
}
}
return ids
}
// hasImageChunks returns true if any chunk is an image_ocr or image_caption type.
func (s *knowledgeBaseService) hasImageChunks(chunks []*types.Chunk) bool {
for _, c := range chunks {
if c.ChunkType == types.ChunkTypeImageOCR || c.ChunkType == types.ChunkTypeImageCaption {
return true
}
}
return false
}
// assembleSearchResults builds the final []*types.SearchResult from chunk data and knowledge data.
// Primary results (from input chunks) are added first in order, then enrichment results.
func (s *knowledgeBaseService) assembleSearchResults(
@@ -174,7 +225,7 @@ func (s *knowledgeBaseService) assembleSearchResults(
logger.Debugf(ctx, "Chunk not found in chunkMap: %s", inputChunk.ChunkID)
continue
}
if !s.isValidTextChunk(chunk) {
if !s.isSearchableChunk(chunk) {
invalidChunkCnt++
if len(invalidChunkSamples) < maxInvalidChunkLog {
invalidChunkSamples = append(invalidChunkSamples, chunk.ID+":"+chunk.ChunkType)
@@ -197,7 +248,7 @@ func (s *knowledgeBaseService) assembleSearchResults(
}
if invalidChunkCnt > 0 {
logger.Debugf(ctx,
"Skip non-text chunks in search results: total=%d sampled=%d samples=%v",
"Skip non-searchable chunks in search results: total=%d sampled=%d samples=%v",
invalidChunkCnt, len(invalidChunkSamples), invalidChunkSamples,
)
}
@@ -205,7 +256,7 @@ func (s *knowledgeBaseService) assembleSearchResults(
// Second pass: Add enrichment chunks (parent, nearby, relation)
if !skipEnrichment {
for chunkID, chunk := range chunkMap {
if addedChunkIDs[chunkID] || !s.isValidTextChunk(chunk) {
if addedChunkIDs[chunkID] || !s.isSearchableChunk(chunk) {
continue
}
@@ -280,11 +331,12 @@ func (s *knowledgeBaseService) buildSearchResult(chunk *types.Chunk,
}
}
// isValidTextChunk checks if a chunk is a valid text chunk.
func (s *knowledgeBaseService) isValidTextChunk(chunk *types.Chunk) bool {
// isSearchableChunk checks if a chunk type should be included in search results.
func (s *knowledgeBaseService) isSearchableChunk(chunk *types.Chunk) bool {
return slices.Contains([]types.ChunkType{
types.ChunkTypeText, types.ChunkTypeSummary,
types.ChunkTypeTableColumn, types.ChunkTypeTableSummary,
types.ChunkTypeFAQ,
types.ChunkTypeImageOCR, types.ChunkTypeImageCaption,
}, chunk.ChunkType)
}
+31
View File
@@ -516,10 +516,41 @@ func resolveStorageProviderPending(db *gorm.DB) {
logger.Infof(context.Background(), "Resolved %d knowledge bases with __pending_env__ storage provider → %s", result.RowsAffected, storageType)
}
// Sync PostgreSQL sequences with actual MAX values to prevent duplicate key
// errors. The old code assigned seq_id via SELECT MAX()+1 in application
// code, which could push values past the DB sequence counter.
syncSequences(db)
// Reset any pending tasks left over from previous aborted runs (Lite App mode)
resetPendingTasks(db)
}
// syncSequences ensures PostgreSQL sequences for auto-increment columns (seq_id)
// are at least as high as the current MAX value in each table. This is needed
// because older code assigned seq_id via application-level MAX()+1, which could
// advance values past the DB sequence counter and cause duplicate key errors.
func syncSequences(db *gorm.DB) {
if db.Dialector.Name() != "postgres" {
return
}
pairs := [][2]string{
{"chunks", "chunks_seq_id_seq"},
{"knowledge_tags", "knowledge_tags_seq_id_seq"},
}
for _, p := range pairs {
table, seq := p[0], p[1]
sql := fmt.Sprintf(
`SELECT setval('%s', GREATEST(nextval('%s'), (SELECT COALESCE(MAX(seq_id), 0) FROM %s)))`,
seq, seq, table,
)
if err := db.Exec(sql).Error; err != nil {
logger.Warnf(context.Background(), "Failed to sync sequence %s: %v", seq, err)
} else {
logger.Infof(context.Background(), "Synced sequence %s with table %s", seq, table)
}
}
}
// resetPendingTasks resets the state of any knowledge items or sync logs stuck in processing
// due to an unexpected application restart when using in-memory queues (Lite mode).
func resetPendingTasks(db *gorm.DB) {
+247
View File
@@ -0,0 +1,247 @@
package logger
import (
"context"
"fmt"
"os"
"path/filepath"
"strings"
"sync"
"time"
)
var llmDebug struct {
mu sync.Mutex
enabled bool
dir string
}
func init() {
configureLLMDebugLog()
}
func configureLLMDebugLog() {
val := strings.TrimSpace(os.Getenv("LLM_DEBUG_LOG"))
if val == "" || val == "false" || val == "0" {
return
}
var dir string
if val == "true" || val == "1" {
dir = resolveLLMDebugDir()
} else {
dir = val
}
if dir == "" {
dir = "llm_debug"
}
if err := os.MkdirAll(dir, 0o755); err != nil {
fmt.Fprintf(os.Stderr, "llm_debug: failed to create dir %s: %v\n", dir, err)
return
}
llmDebug.dir = dir
llmDebug.enabled = true
go cleanupOldDebugFiles(dir, 7*24*time.Hour)
fmt.Fprintf(os.Stderr, "llm_debug: LLM debug log enabled → %s/\n", dir)
}
func resolveLLMDebugDir() string {
if logPath := strings.TrimSpace(os.Getenv("LOG_PATH")); logPath != "" {
return filepath.Join(filepath.Dir(logPath), "llm_debug")
}
if macPath := defaultMacAppLogPath(); macPath != "" {
return filepath.Join(filepath.Dir(macPath), "llm_debug")
}
return "llm_debug"
}
// cleanupOldDebugFiles removes files older than maxAge from the debug directory.
func cleanupOldDebugFiles(dir string, maxAge time.Duration) {
entries, err := os.ReadDir(dir)
if err != nil {
return
}
cutoff := time.Now().Add(-maxAge)
for _, e := range entries {
if e.IsDir() {
continue
}
info, err := e.Info()
if err != nil {
continue
}
if info.ModTime().Before(cutoff) {
_ = os.Remove(filepath.Join(dir, e.Name()))
}
}
}
// LLMDebugEnabled returns true when the dedicated LLM debug log is active.
func LLMDebugEnabled() bool {
return llmDebug.enabled
}
// LLMDebugLog writes a complete model call record to a per-request log file.
// All calls sharing the same request_id are appended to the same file.
func LLMDebugLog(ctx context.Context, record *LLMCallRecord) {
if !llmDebug.enabled || record == nil {
return
}
text := formatRecord(record)
reqID := extractRequestID(ctx)
filename := buildFilename(reqID)
llmDebug.mu.Lock()
defer llmDebug.mu.Unlock()
path := filepath.Join(llmDebug.dir, filename)
f, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o644)
if err != nil {
fmt.Fprintf(os.Stderr, "llm_debug: open %s: %v\n", path, err)
return
}
defer f.Close()
_, _ = f.WriteString(text)
}
func buildFilename(reqID string) string {
if reqID != "" {
return reqID + ".log"
}
return time.Now().Format("20060102_150405.000") + ".log"
}
func formatRecord(r *LLMCallRecord) string {
var b strings.Builder
b.Grow(4096)
separator := fmt.Sprintf("================ %s ================", r.CallType)
b.WriteString("\n")
b.WriteString(separator)
b.WriteString("\n")
b.WriteString(fmt.Sprintf("Time: %s\n", time.Now().Format("2006-01-02 15:04:05.000")))
b.WriteString(fmt.Sprintf("Model: %s\n", r.Model))
if r.Duration > 0 {
b.WriteString(fmt.Sprintf("Duration: %s\n", r.Duration.Round(time.Millisecond)))
}
for _, s := range r.Sections {
b.WriteString(fmt.Sprintf("\n---------- %s ----------\n", s.Title))
b.WriteString(s.Content)
if !strings.HasSuffix(s.Content, "\n") {
b.WriteString("\n")
}
}
if r.Error != "" {
b.WriteString("\n---------- Error ----------\n")
b.WriteString(r.Error)
b.WriteString("\n")
}
b.WriteString(strings.Repeat("=", len(separator)))
b.WriteString("\n")
return b.String()
}
func extractRequestID(ctx context.Context) string {
entry := GetLogger(ctx)
if v, ok := entry.Data["request_id"]; ok {
return fmt.Sprintf("%v", v)
}
return ""
}
// ---------- Record types ----------
// LLMCallRecord holds all information for one model API call.
type LLMCallRecord struct {
CallType string // "Chat", "Chat Stream", "Embedding", "Rerank", "VLM"
Model string
Duration time.Duration
Sections []RecordSection
Error string
}
// RecordSection is a titled block of text within a call record.
type RecordSection struct {
Title string
Content string
}
// ---------- Shared helpers for building sections ----------
// LLMMessage is a simplified chat message for logging.
type LLMMessage struct {
Role string
Content string
Name string
ToolCallID string
Images []string
ToolCalls []LLMToolCallInfo
}
// LLMToolCallInfo holds tool call info for logging.
type LLMToolCallInfo struct {
ID string
FuncName string
Arguments string
}
// FormatMessages formats chat messages into a readable block.
func FormatMessages(messages []LLMMessage) string {
var b strings.Builder
for _, m := range messages {
b.WriteString(fmt.Sprintf("[%s]", m.Role))
if m.Name != "" {
b.WriteString(fmt.Sprintf(" name=%s", m.Name))
}
if m.ToolCallID != "" {
b.WriteString(fmt.Sprintf(" tool_call_id=%s", m.ToolCallID))
}
b.WriteString("\n")
if m.Content != "" {
b.WriteString(m.Content)
b.WriteString("\n")
}
for _, img := range m.Images {
if len([]rune(img)) > 80 {
b.WriteString(fmt.Sprintf("[image: %s (%d bytes)]\n", TruncateRunes(img, 80), len(img)))
} else {
b.WriteString(fmt.Sprintf("[image: %s]\n", img))
}
}
for _, tc := range m.ToolCalls {
b.WriteString(fmt.Sprintf(" -> tool_call: id=%s, func=%s, args=%s\n", tc.ID, tc.FuncName, tc.Arguments))
}
b.WriteString("\n")
}
return b.String()
}
// FormatToolCalls formats response tool calls into a readable block.
func FormatToolCalls(tcs []LLMToolCallInfo) string {
var b strings.Builder
for _, tc := range tcs {
b.WriteString(fmt.Sprintf("[tool_call] id=%s, func=%s\n%s\n\n", tc.ID, tc.FuncName, tc.Arguments))
}
return b.String()
}
// TruncateRunes truncates a string to maxRunes runes, appending "..." if truncated.
// This is safe for multi-byte UTF-8 characters (e.g. Chinese).
func TruncateRunes(s string, maxRunes int) string {
runes := []rune(s)
if len(runes) <= maxRunes {
return s
}
return string(runes[:maxRunes]) + "..."
}
+5 -2
View File
@@ -107,14 +107,17 @@ type ChatConfig struct {
// NewChat 创建聊天实例
func NewChat(config *ChatConfig, ollamaService *ollama.OllamaService) (Chat, error) {
var c Chat
var err error
switch strings.ToLower(string(config.Source)) {
case string(types.ModelSourceLocal):
return NewOllamaChat(config, ollamaService)
c, err = NewOllamaChat(config, ollamaService)
case string(types.ModelSourceRemote):
return NewRemoteChat(config)
c, err = NewRemoteChat(config)
default:
return nil, fmt.Errorf("unsupported chat model source: %s", config.Source)
}
return wrapChatDebug(c, err)
}
// NewRemoteChat 根据 provider 创建远程聊天实例
+214
View File
@@ -0,0 +1,214 @@
package chat
import (
"context"
"fmt"
"strings"
"time"
"github.com/Tencent/WeKnora/internal/logger"
"github.com/Tencent/WeKnora/internal/types"
)
func buildLLMMessages(messages []Message) []logger.LLMMessage {
out := make([]logger.LLMMessage, 0, len(messages))
for _, m := range messages {
lm := logger.LLMMessage{
Role: m.Role,
Content: m.Content,
Name: m.Name,
ToolCallID: m.ToolCallID,
Images: m.Images,
}
if lm.Content == "" && len(m.MultiContent) > 0 {
var parts []string
for _, mc := range m.MultiContent {
switch mc.Type {
case "text":
parts = append(parts, mc.Text)
case "image_url":
if mc.ImageURL != nil {
parts = append(parts, fmt.Sprintf("[image_url: %s]", truncateForDebug(mc.ImageURL.URL, 120)))
}
}
}
lm.Content = strings.Join(parts, "\n")
}
for _, tc := range m.ToolCalls {
lm.ToolCalls = append(lm.ToolCalls, logger.LLMToolCallInfo{
ID: tc.ID,
FuncName: tc.Function.Name,
Arguments: tc.Function.Arguments,
})
}
out = append(out, lm)
}
return out
}
func buildOptionsSection(opts *ChatOptions) string {
if opts == nil {
return ""
}
var parts []string
parts = append(parts, fmt.Sprintf("Temperature=%.2f", opts.Temperature))
if opts.TopP > 0 {
parts = append(parts, fmt.Sprintf("TopP=%.2f", opts.TopP))
}
if opts.MaxTokens > 0 {
parts = append(parts, fmt.Sprintf("MaxTokens=%d", opts.MaxTokens))
}
if opts.MaxCompletionTokens > 0 {
parts = append(parts, fmt.Sprintf("MaxCompletionTokens=%d", opts.MaxCompletionTokens))
}
if opts.FrequencyPenalty > 0 {
parts = append(parts, fmt.Sprintf("FrequencyPenalty=%.2f", opts.FrequencyPenalty))
}
if opts.PresencePenalty > 0 {
parts = append(parts, fmt.Sprintf("PresencePenalty=%.2f", opts.PresencePenalty))
}
if opts.ToolChoice != "" {
parts = append(parts, fmt.Sprintf("ToolChoice=%s", opts.ToolChoice))
}
if len(opts.Format) > 0 {
parts = append(parts, "ResponseFormat=json_object")
}
return strings.Join(parts, ", ")
}
func buildToolsSection(opts *ChatOptions) string {
if opts == nil || len(opts.Tools) == 0 {
return ""
}
var b strings.Builder
for i, t := range opts.Tools {
if i > 0 {
b.WriteString("\n")
}
b.WriteString(fmt.Sprintf("- %s: %s", t.Function.Name, t.Function.Description))
}
return b.String()
}
func buildResponseToolCalls(tcs []types.LLMToolCall) []logger.LLMToolCallInfo {
if len(tcs) == 0 {
return nil
}
out := make([]logger.LLMToolCallInfo, 0, len(tcs))
for _, tc := range tcs {
out = append(out, logger.LLMToolCallInfo{
ID: tc.ID,
FuncName: tc.Function.Name,
Arguments: tc.Function.Arguments,
})
}
return out
}
func usageString(u types.TokenUsage) string {
return fmt.Sprintf("Prompt: %d, Completion: %d, Total: %d",
u.PromptTokens, u.CompletionTokens, u.TotalTokens)
}
// logLLMDebugCall logs a complete non-stream LLM chat call.
func logLLMDebugCall(ctx context.Context, model string, messages []Message, opts *ChatOptions, resp *types.ChatResponse, callErr error, dur time.Duration) {
if !logger.LLMDebugEnabled() {
return
}
record := &logger.LLMCallRecord{
CallType: "Chat",
Model: model,
Duration: dur,
}
record.Sections = append(record.Sections, logger.RecordSection{
Title: "Messages",
Content: logger.FormatMessages(buildLLMMessages(messages)),
})
if s := buildOptionsSection(opts); s != "" {
record.Sections = append(record.Sections, logger.RecordSection{Title: "Options", Content: s})
}
if s := buildToolsSection(opts); s != "" {
record.Sections = append(record.Sections, logger.RecordSection{Title: "Tools", Content: s})
}
if resp != nil {
var respText strings.Builder
if resp.Content != "" {
respText.WriteString("[assistant]\n")
respText.WriteString(resp.Content)
respText.WriteString("\n")
}
tcs := buildResponseToolCalls(resp.ToolCalls)
if len(tcs) > 0 {
respText.WriteString(logger.FormatToolCalls(tcs))
}
if respText.Len() > 0 {
record.Sections = append(record.Sections, logger.RecordSection{Title: "Response", Content: respText.String()})
}
record.Sections = append(record.Sections, logger.RecordSection{Title: "Usage", Content: usageString(resp.Usage)})
}
if callErr != nil {
record.Error = callErr.Error()
}
logger.LLMDebugLog(ctx, record)
}
// logLLMDebugStream logs a complete stream LLM chat call after all chunks have been received.
func logLLMDebugStream(ctx context.Context, model string, messages []Message, opts *ChatOptions, fullContent string, toolCalls []types.LLMToolCall, usage *types.TokenUsage, callErr error, dur time.Duration) {
if !logger.LLMDebugEnabled() {
return
}
record := &logger.LLMCallRecord{
CallType: "Chat Stream",
Model: model,
Duration: dur,
}
record.Sections = append(record.Sections, logger.RecordSection{
Title: "Messages",
Content: logger.FormatMessages(buildLLMMessages(messages)),
})
if s := buildOptionsSection(opts); s != "" {
record.Sections = append(record.Sections, logger.RecordSection{Title: "Options", Content: s})
}
if s := buildToolsSection(opts); s != "" {
record.Sections = append(record.Sections, logger.RecordSection{Title: "Tools", Content: s})
}
var respText strings.Builder
if fullContent != "" {
respText.WriteString("[assistant]\n")
respText.WriteString(fullContent)
respText.WriteString("\n")
}
tcs := buildResponseToolCalls(toolCalls)
if len(tcs) > 0 {
respText.WriteString(logger.FormatToolCalls(tcs))
}
if respText.Len() > 0 {
record.Sections = append(record.Sections, logger.RecordSection{Title: "Response", Content: respText.String()})
}
if usage != nil {
record.Sections = append(record.Sections, logger.RecordSection{Title: "Usage", Content: usageString(*usage)})
}
if callErr != nil {
record.Error = callErr.Error()
}
logger.LLMDebugLog(ctx, record)
}
func truncateForDebug(s string, maxRunes int) string {
runes := []rune(s)
if len(runes) <= maxRunes {
return s
}
return string(runes[:maxRunes]) + fmt.Sprintf("...(%d chars)", len(runes))
}
+77
View File
@@ -0,0 +1,77 @@
package chat
import (
"context"
"fmt"
"strings"
"time"
"github.com/Tencent/WeKnora/internal/logger"
"github.com/Tencent/WeKnora/internal/types"
)
// debugChat wraps a Chat implementation and logs all calls to the LLM debug log.
// It works with both RemoteAPIChat and OllamaChat (or any future Chat impl).
type debugChat struct {
inner Chat
}
func (d *debugChat) GetModelName() string { return d.inner.GetModelName() }
func (d *debugChat) GetModelID() string { return d.inner.GetModelID() }
func (d *debugChat) Chat(ctx context.Context, messages []Message, opts *ChatOptions) (*types.ChatResponse, error) {
callStart := time.Now()
resp, err := d.inner.Chat(ctx, messages, opts)
logLLMDebugCall(ctx, d.inner.GetModelName(), messages, opts, resp, err, time.Since(callStart))
return resp, err
}
func (d *debugChat) ChatStream(ctx context.Context, messages []Message, opts *ChatOptions) (<-chan types.StreamResponse, error) {
callStart := time.Now()
ch, err := d.inner.ChatStream(ctx, messages, opts)
if err != nil {
logLLMDebugStream(ctx, d.inner.GetModelName(), messages, opts, "", nil, nil, err, time.Since(callStart))
return ch, err
}
if ch == nil {
return nil, nil
}
wrapped := make(chan types.StreamResponse)
go func() {
defer close(wrapped)
var content strings.Builder
var usage *types.TokenUsage
var toolCalls []types.LLMToolCall
var streamErr error
for resp := range ch {
if resp.ResponseType == types.ResponseTypeAnswer && resp.Content != "" {
content.WriteString(resp.Content)
}
if resp.ResponseType == types.ResponseTypeError {
streamErr = fmt.Errorf("%s", resp.Content)
}
if resp.Usage != nil {
usage = resp.Usage
}
if len(resp.ToolCalls) > 0 {
toolCalls = resp.ToolCalls
}
wrapped <- resp
}
logLLMDebugStream(ctx, d.inner.GetModelName(), messages, opts,
content.String(), toolCalls, usage, streamErr, time.Since(callStart))
}()
return wrapped, nil
}
// wrapChatDebug wraps a Chat if LLM debug logging is enabled.
func wrapChatDebug(c Chat, err error) (Chat, error) {
if err != nil || !logger.LLMDebugEnabled() {
return c, err
}
return &debugChat{inner: c}, nil
}
+6 -4
View File
@@ -570,11 +570,12 @@ func (c *RemoteAPIChat) processStream(ctx context.Context, stream *openai.ChatCo
logger.Infof(ctx, "[LLM Usage] model=%s, prompt_tokens=%d, completion_tokens=%d, total_tokens=%d",
c.modelName, state.usage.PromptTokens, state.usage.CompletionTokens, state.usage.TotalTokens)
}
toolCalls := state.buildOrderedToolCalls()
streamChan <- types.StreamResponse{
ResponseType: types.ResponseTypeAnswer,
Content: "",
Done: true,
ToolCalls: state.buildOrderedToolCalls(),
ToolCalls: toolCalls,
Usage: state.usage,
FinishReason: state.lastFinishReason,
}
@@ -614,16 +615,16 @@ func (c *RemoteAPIChat) processRawHTTPStream(ctx context.Context, resp *http.Res
event, err := reader.ReadEvent()
if err != nil {
if err == io.EOF {
// 部分模型不发送 [DONE] 标记,直接关闭连接,视为正常结束
if state.usage != nil {
logger.Infof(ctx, "[LLM Usage] model=%s, prompt_tokens=%d, completion_tokens=%d, total_tokens=%d",
c.modelName, state.usage.PromptTokens, state.usage.CompletionTokens, state.usage.TotalTokens)
}
toolCalls := state.buildOrderedToolCalls()
streamChan <- types.StreamResponse{
ResponseType: types.ResponseTypeAnswer,
Content: "",
Done: true,
ToolCalls: state.buildOrderedToolCalls(),
ToolCalls: toolCalls,
Usage: state.usage,
}
} else {
@@ -646,11 +647,12 @@ func (c *RemoteAPIChat) processRawHTTPStream(ctx context.Context, resp *http.Res
logger.Infof(ctx, "[LLM Usage] model=%s, prompt_tokens=%d, completion_tokens=%d, total_tokens=%d",
c.modelName, state.usage.PromptTokens, state.usage.CompletionTokens, state.usage.TotalTokens)
}
toolCalls := state.buildOrderedToolCalls()
streamChan <- types.StreamResponse{
ResponseType: types.ResponseTypeAnswer,
Content: "",
Done: true,
ToolCalls: state.buildOrderedToolCalls(),
ToolCalls: toolCalls,
Usage: state.usage,
}
return
+9
View File
@@ -5,6 +5,7 @@ import (
"fmt"
"strings"
"github.com/Tencent/WeKnora/internal/logger"
"github.com/Tencent/WeKnora/internal/models/provider"
"github.com/Tencent/WeKnora/internal/models/utils/ollama"
"github.com/Tencent/WeKnora/internal/types"
@@ -54,6 +55,14 @@ type Config struct {
// NewEmbedder creates an embedder based on the configuration
func NewEmbedder(config Config, pooler EmbedderPooler, ollamaService *ollama.OllamaService) (Embedder, error) {
e, err := newEmbedder(config, pooler, ollamaService)
if err != nil || !logger.LLMDebugEnabled() {
return e, err
}
return &debugEmbedder{inner: e}, nil
}
func newEmbedder(config Config, pooler EmbedderPooler, ollamaService *ollama.OllamaService) (Embedder, error) {
var embedder Embedder
var err error
switch strings.ToLower(string(config.Source)) {
+93
View File
@@ -0,0 +1,93 @@
package embedding
import (
"context"
"fmt"
"strings"
"time"
"github.com/Tencent/WeKnora/internal/logger"
)
// debugEmbedder wraps an Embedder with LLM debug logging.
type debugEmbedder struct {
inner Embedder
}
func (d *debugEmbedder) Embed(ctx context.Context, text string) ([]float32, error) {
start := time.Now()
result, err := d.inner.Embed(ctx, text)
logEmbeddingDebug(ctx, d.inner.GetModelName(), []string{text}, singleToDouble(result), err, time.Since(start))
return result, err
}
func (d *debugEmbedder) BatchEmbed(ctx context.Context, texts []string) ([][]float32, error) {
start := time.Now()
result, err := d.inner.BatchEmbed(ctx, texts)
logEmbeddingDebug(ctx, d.inner.GetModelName(), texts, result, err, time.Since(start))
return result, err
}
func (d *debugEmbedder) BatchEmbedWithPool(ctx context.Context, model Embedder, texts []string) ([][]float32, error) {
return d.inner.BatchEmbedWithPool(ctx, d, texts)
}
func (d *debugEmbedder) GetModelName() string { return d.inner.GetModelName() }
func (d *debugEmbedder) GetDimensions() int { return d.inner.GetDimensions() }
func (d *debugEmbedder) GetModelID() string { return d.inner.GetModelID() }
func singleToDouble(v []float32) [][]float32 {
if v == nil {
return nil
}
return [][]float32{v}
}
func logEmbeddingDebug(ctx context.Context, model string, inputs []string, outputs [][]float32, callErr error, dur time.Duration) {
if !logger.LLMDebugEnabled() {
return
}
record := &logger.LLMCallRecord{
CallType: "Embedding",
Model: model,
Duration: dur,
}
// Input section: show each text with a preview
var inputBuf strings.Builder
inputBuf.WriteString(fmt.Sprintf("count=%d\n", len(inputs)))
for i, t := range inputs {
preview := strings.ReplaceAll(t, "\n", "\\n")
preview = logger.TruncateRunes(preview, 200)
inputBuf.WriteString(fmt.Sprintf("[%d] (len=%d) %s\n", i, len([]rune(t)), preview))
}
record.Sections = append(record.Sections, logger.RecordSection{Title: "Input", Content: inputBuf.String()})
// Output section
if outputs != nil {
var outBuf strings.Builder
outBuf.WriteString(fmt.Sprintf("count=%d\n", len(outputs)))
for i, vec := range outputs {
if len(vec) > 0 {
outBuf.WriteString(fmt.Sprintf("[%d] dims=%d, first_3=[%.6f, %.6f, %.6f]\n", i, len(vec),
safeIdx(vec, 0), safeIdx(vec, 1), safeIdx(vec, 2)))
} else {
outBuf.WriteString(fmt.Sprintf("[%d] empty\n", i))
}
}
record.Sections = append(record.Sections, logger.RecordSection{Title: "Output", Content: outBuf.String()})
}
if callErr != nil {
record.Error = callErr.Error()
}
logger.LLMDebugLog(ctx, record)
}
func safeIdx(v []float32, i int) float32 {
if i < len(v) {
return v[i]
}
return 0
}
+70
View File
@@ -0,0 +1,70 @@
package rerank
import (
"context"
"fmt"
"strings"
"time"
"github.com/Tencent/WeKnora/internal/logger"
)
// debugReranker wraps a Reranker with LLM debug logging.
type debugReranker struct {
inner Reranker
}
func (d *debugReranker) Rerank(ctx context.Context, query string, documents []string) ([]RankResult, error) {
start := time.Now()
result, err := d.inner.Rerank(ctx, query, documents)
logRerankDebug(ctx, d.inner.GetModelName(), query, documents, result, err, time.Since(start))
return result, err
}
func (d *debugReranker) GetModelName() string { return d.inner.GetModelName() }
func (d *debugReranker) GetModelID() string { return d.inner.GetModelID() }
func logRerankDebug(ctx context.Context, model string, query string, documents []string, results []RankResult, callErr error, dur time.Duration) {
if !logger.LLMDebugEnabled() {
return
}
record := &logger.LLMCallRecord{
CallType: "Rerank",
Model: model,
Duration: dur,
}
// Query section
record.Sections = append(record.Sections, logger.RecordSection{
Title: "Query",
Content: query,
})
// Documents section
var docBuf strings.Builder
docBuf.WriteString(fmt.Sprintf("count=%d\n", len(documents)))
for i, doc := range documents {
preview := strings.ReplaceAll(doc, "\n", "\\n")
preview = logger.TruncateRunes(preview, 200)
docBuf.WriteString(fmt.Sprintf("[%d] (len=%d) %s\n", i, len([]rune(doc)), preview))
}
record.Sections = append(record.Sections, logger.RecordSection{Title: "Documents", Content: docBuf.String()})
// Results section
if results != nil {
var resBuf strings.Builder
resBuf.WriteString(fmt.Sprintf("count=%d\n", len(results)))
for _, r := range results {
docPreview := strings.ReplaceAll(r.Document.Text, "\n", "\\n")
docPreview = logger.TruncateRunes(docPreview, 200)
resBuf.WriteString(fmt.Sprintf(" [%d] score=%.6f %s\n", r.Index, r.RelevanceScore, docPreview))
}
record.Sections = append(record.Sections, logger.RecordSection{Title: "Results", Content: resBuf.String()})
}
if callErr != nil {
record.Error = callErr.Error()
}
logger.LLMDebugLog(ctx, record)
}
+9
View File
@@ -5,6 +5,7 @@ import (
"encoding/json"
"fmt"
"github.com/Tencent/WeKnora/internal/logger"
"github.com/Tencent/WeKnora/internal/models/provider"
"github.com/Tencent/WeKnora/internal/types"
)
@@ -91,6 +92,14 @@ type RerankerConfig struct {
// NewReranker creates a reranker based on the configuration
func NewReranker(config *RerankerConfig) (Reranker, error) {
r, err := newReranker(config)
if err != nil || !logger.LLMDebugEnabled() {
return r, err
}
return &debugReranker{inner: r}, nil
}
func newReranker(config *RerankerConfig) (Reranker, error) {
// Use provider field if set, otherwise detect from URL using provider registry
providerName := provider.ProviderName(config.Provider)
if providerName == "" {
+63
View File
@@ -0,0 +1,63 @@
package vlm
import (
"context"
"fmt"
"strings"
"time"
"github.com/Tencent/WeKnora/internal/logger"
)
// debugVLM wraps a VLM with LLM debug logging.
type debugVLM struct {
inner VLM
}
func (d *debugVLM) Predict(ctx context.Context, imgBytes [][]byte, prompt string) (string, error) {
start := time.Now()
result, err := d.inner.Predict(ctx, imgBytes, prompt)
logVLMDebug(ctx, d.inner.GetModelName(), imgBytes, prompt, result, err, time.Since(start))
return result, err
}
func (d *debugVLM) GetModelName() string { return d.inner.GetModelName() }
func (d *debugVLM) GetModelID() string { return d.inner.GetModelID() }
func logVLMDebug(ctx context.Context, model string, imgBytes [][]byte, prompt string, response string, callErr error, dur time.Duration) {
if !logger.LLMDebugEnabled() {
return
}
record := &logger.LLMCallRecord{
CallType: "VLM",
Model: model,
Duration: dur,
}
// Input section
var inputBuf strings.Builder
inputBuf.WriteString(fmt.Sprintf("Images: count=%d", len(imgBytes)))
totalSize := 0
for _, img := range imgBytes {
totalSize += len(img)
}
inputBuf.WriteString(fmt.Sprintf(", total_size=%d bytes\n\n", totalSize))
inputBuf.WriteString("[prompt]\n")
inputBuf.WriteString(prompt)
inputBuf.WriteString("\n")
record.Sections = append(record.Sections, logger.RecordSection{Title: "Input", Content: inputBuf.String()})
// Response section
if response != "" {
record.Sections = append(record.Sections, logger.RecordSection{
Title: "Response",
Content: response,
})
}
if callErr != nil {
record.Error = callErr.Error()
}
logger.LLMDebugLog(ctx, record)
}
+9
View File
@@ -5,6 +5,7 @@ import (
"fmt"
"strings"
"github.com/Tencent/WeKnora/internal/logger"
"github.com/Tencent/WeKnora/internal/models/provider"
"github.com/Tencent/WeKnora/internal/models/utils/ollama"
"github.com/Tencent/WeKnora/internal/types"
@@ -35,6 +36,14 @@ type Config struct {
// NewVLM creates a VLM instance based on the provided configuration.
func NewVLM(config *Config, ollamaService *ollama.OllamaService) (VLM, error) {
v, err := newVLM(config, ollamaService)
if err != nil || !logger.LLMDebugEnabled() {
return v, err
}
return &debugVLM{inner: v}, nil
}
func newVLM(config *Config, ollamaService *ollama.OllamaService) (VLM, error) {
ifType := strings.ToLower(config.InterfaceType)
if ifType == "ollama" || config.Source == types.ModelSourceLocal {
+156
View File
@@ -0,0 +1,156 @@
package searchutil
import (
"context"
"encoding/json"
"github.com/Tencent/WeKnora/internal/types"
"github.com/Tencent/WeKnora/internal/types/interfaces"
)
// CollectImageInfoByChunkIDs collects merged image_info JSON for each given
// chunk ID by querying child chunks (image_ocr / image_caption). It supports
// two-level resolution:
// - If chunkIDs are text chunks, their direct children are image chunks → one query.
// - If chunkIDs are parent_text chunks, their children are text chunks
// whose children are image chunks → two queries.
//
// Returns a map of input chunkID → merged image_info JSON string.
func CollectImageInfoByChunkIDs(
ctx context.Context,
chunkRepo interfaces.ChunkRepository,
tenantID uint64,
chunkIDs []string,
) map[string]string {
if len(chunkIDs) == 0 {
return nil
}
children, err := chunkRepo.ListChunksByParentIDs(ctx, tenantID, chunkIDs)
if err != nil || len(children) == 0 {
return nil
}
type imageAgg struct {
byURL map[string]types.ImageInfo
}
aggMap := make(map[string]*imageAgg)
addInfo := func(targetID string, child *types.Chunk) {
if child.ImageInfo == "" {
return
}
var infos []types.ImageInfo
if err := json.Unmarshal([]byte(child.ImageInfo), &infos); err != nil || len(infos) == 0 {
return
}
agg, ok := aggMap[targetID]
if !ok {
agg = &imageAgg{byURL: make(map[string]types.ImageInfo)}
aggMap[targetID] = agg
}
for _, info := range infos {
key := info.URL
if key == "" {
key = info.OriginalURL
}
if key == "" {
continue
}
existing, exists := agg.byURL[key]
if !exists {
agg.byURL[key] = info
} else {
if info.OCRText != "" {
existing.OCRText = info.OCRText
}
if info.Caption != "" {
existing.Caption = info.Caption
}
agg.byURL[key] = existing
}
}
}
var textChildIDs []string
textToParent := make(map[string]string)
for _, child := range children {
switch child.ChunkType {
case types.ChunkTypeImageOCR, types.ChunkTypeImageCaption:
addInfo(child.ParentChunkID, child)
case types.ChunkTypeText:
textChildIDs = append(textChildIDs, child.ID)
textToParent[child.ID] = child.ParentChunkID
}
}
if len(textChildIDs) > 0 {
grandChildren, err := chunkRepo.ListChunksByParentIDs(ctx, tenantID, textChildIDs)
if err == nil {
for _, gc := range grandChildren {
if gc.ChunkType != types.ChunkTypeImageOCR && gc.ChunkType != types.ChunkTypeImageCaption {
continue
}
if parentTextID, ok := textToParent[gc.ParentChunkID]; ok {
addInfo(parentTextID, gc)
}
}
}
}
out := make(map[string]string, len(aggMap))
for id, agg := range aggMap {
if len(agg.byURL) == 0 {
continue
}
merged := make([]types.ImageInfo, 0, len(agg.byURL))
for _, info := range agg.byURL {
merged = append(merged, info)
}
data, err := json.Marshal(merged)
if err != nil {
continue
}
out[id] = string(data)
}
return out
}
// EnrichSearchResultsImageInfo fills in ImageInfo for SearchResults that have
// none by batch-querying child image chunks.
func EnrichSearchResultsImageInfo(
ctx context.Context,
chunkRepo interfaces.ChunkRepository,
tenantID uint64,
results []*types.SearchResult,
) {
var chunkIDs []string
seen := make(map[string]bool)
for _, r := range results {
if r.ImageInfo != "" {
continue
}
if !seen[r.ID] {
seen[r.ID] = true
chunkIDs = append(chunkIDs, r.ID)
}
}
if len(chunkIDs) == 0 {
return
}
infoMap := CollectImageInfoByChunkIDs(ctx, chunkRepo, tenantID, chunkIDs)
if len(infoMap) == 0 {
return
}
for _, r := range results {
if r.ImageInfo != "" {
continue
}
if merged, ok := infoMap[r.ID]; ok {
r.ImageInfo = merged
}
}
}
+5
View File
@@ -32,7 +32,12 @@ type KnowledgeTag struct {
// BeforeCreate ensures SeqID is populated for databases that don't support
// autoIncrement on non-primary-key columns (e.g. SQLite).
// On PostgreSQL/MySQL the DB sequence handles this, so we skip to avoid
// duplicate key races under concurrent inserts.
func (t *KnowledgeTag) BeforeCreate(tx *gorm.DB) error {
if tx.Dialector.Name() != "sqlite" {
return nil
}
if t.SeqID == 0 {
var maxSeqID *int64
tx.Unscoped().Model(&KnowledgeTag{}).