Files
WeKnora/internal/logger/logger.go
T
wizardchen b6d3420a5d fix: harden document pipeline concurrency and diagnostics
- docreader: serialize all pdfium access behind a global lock. pypdfium2
  is process-global and not thread-safe, so concurrent PDF uploads could
  corrupt its shared state and deadlock the whole process (requests stuck
  in "Parsing document" forever). Non-PDF parsers still run concurrently.
- logger: strip ANSI color escapes from file logs so on-disk logs stay
  plain text while stdout keeps terminal colors.
- storage: log baseDir/resolvedPath on file-open failure and when the
  multimodal service resolves a file service, so a LOCAL_STORAGE_BASE_DIR
  mismatch between writer and reader is immediately visible.
- docker: set TZ (default Asia/Shanghai) for the docreader container.
2026-07-09 13:26:40 +08:00

543 lines
15 KiB
Go
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
package logger
import (
"context"
"fmt"
"io"
"os"
"path"
"path/filepath"
"regexp"
"runtime"
"sort"
"strings"
"sync"
"github.com/Tencent/WeKnora/internal/types"
"github.com/sirupsen/logrus"
"gopkg.in/natefinch/lumberjack.v2"
)
// appLogger 使用私有实例,避免外部依赖改写 logrus 全局状态导致日志丢失
var appLogger = logrus.New()
var (
loggerMu sync.Mutex
activeLogFile io.WriteCloser
ansiEscapeRE = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`)
)
// ansiStripWriter removes ANSI color/style sequences so file logs stay plain text
// while stdout can still render colors in a terminal.
type ansiStripWriter struct {
w io.Writer
}
func (s *ansiStripWriter) Write(p []byte) (int, error) {
_, err := s.w.Write(ansiEscapeRE.ReplaceAll(p, nil))
return len(p), err
}
// LogLevel 日志级别类型
type LogLevel string
// 日志级别常量
const (
LevelDebug LogLevel = "debug"
LevelInfo LogLevel = "info"
LevelWarn LogLevel = "warn"
LevelError LogLevel = "error"
LevelFatal LogLevel = "fatal"
)
// ANSI颜色代码
const (
colorRed = "\033[31m"
colorGreen = "\033[32m"
colorYellow = "\033[33m"
colorBlue = "\033[34m"
colorPurple = "\033[35m"
colorCyan = "\033[36m"
colorWhite = "\033[37m"
colorGray = "\033[90m"
colorBold = "\033[1m"
colorReset = "\033[0m"
)
type CustomFormatter struct {
ForceColor bool // 是否强制使用颜色,即使在非终端环境下
Template string // 自定义日志格式模板,通过 LOG_FORMAT 环境变量配置,为空则使用内置默认格式
// 模板占位符:%d=时间 %level=级别 %thread=goroutine %logger=caller %traceId=请求ID %msg=消息+结构化字段
// threadNeeded 缓存模板是否引用了 %thread,避免每条日志都调用一次 runtime.Stack。
threadNeeded bool
}
// levelColorFor 返回日志级别对应的 ANSI 颜色码,无颜色时返回空串。
func levelColorFor(level logrus.Level) string {
switch level {
case logrus.DebugLevel:
return colorCyan
case logrus.InfoLevel:
return colorGreen
case logrus.WarnLevel:
return colorYellow
case logrus.ErrorLevel:
return colorRed
case logrus.FatalLevel:
return colorPurple
}
return ""
}
func (f *CustomFormatter) Format(entry *logrus.Entry) ([]byte, error) {
timestamp := entry.Time.Format("2006-01-02 15:04:05.000")
level := strings.ToUpper(entry.Level.String())
// 提取已知字段
caller, _ := entry.Data["caller"].(string)
traceID, _ := entry.Data["request_id"].(string)
// 剩余结构化字段
keys := make([]string, 0, len(entry.Data))
for k := range entry.Data {
if k != "caller" && k != "request_id" {
keys = append(keys, k)
}
}
sort.Strings(keys)
// 自定义模板模式
if f.Template != "" {
msg := entry.Message
for _, k := range keys {
msg += fmt.Sprintf(" %s=%v", k, entry.Data[k])
}
shortCaller := caller
if len(shortCaller) > 50 {
shortCaller = shortCaller[len(shortCaller)-50:]
}
// 仅在模板引用 %thread 时才取 goroutine ID,避免每条日志都执行 runtime.Stack
thread := ""
if f.threadNeeded {
thread = getGoroutineID()
}
// 级别染色在占位符替换阶段完成,避免后续在整行做 ReplaceAll
// 误染消息内容里出现的 "INFO"/"ERROR" 等字面字符串。
levelOut := level
if f.ForceColor {
if c := levelColorFor(entry.Level); c != "" {
levelOut = c + level + colorReset
}
}
// 使用 NewReplacer 做单趟替换,避免链式 ReplaceAll 时
// 前一个占位符的值里恰好包含后续占位符字面串导致的二次替换。
r := strings.NewReplacer(
"%d", timestamp,
"%level", levelOut,
"%thread", thread,
"%logger", shortCaller,
"%traceId", traceID,
"%msg", msg,
)
return []byte(r.Replace(f.Template) + "\n"), nil
}
// 默认格式(保持原有行为)
var levelColor, resetColor string
if f.ForceColor {
switch entry.Level {
case logrus.DebugLevel:
levelColor = colorCyan
case logrus.InfoLevel:
levelColor = colorGreen
case logrus.WarnLevel:
levelColor = colorYellow
case logrus.ErrorLevel:
levelColor = colorRed
case logrus.FatalLevel:
levelColor = colorPurple
default:
levelColor = colorReset
}
resetColor = colorReset
}
fields := ""
// request_id 优先输出
if v, ok := entry.Data["request_id"]; ok {
if f.ForceColor {
fields += fmt.Sprintf("%s%v%s ",
colorBlue, v, colorReset)
} else {
fields += fmt.Sprintf("%v ", v)
}
}
// 其余字段排序后输出
for _, k := range keys {
if f.ForceColor {
val := fmt.Sprintf("%v", entry.Data[k])
coloredVal := fmt.Sprintf("%s%s%s", colorWhite, val, colorReset)
if k == "error" {
coloredVal = fmt.Sprintf("%s%s%s", colorRed, val, colorReset)
}
fields += fmt.Sprintf("%s%s%s=%s ",
colorCyan, k, colorReset, coloredVal)
} else {
fields += fmt.Sprintf("%s=%v ", k, entry.Data[k])
}
}
fields = strings.TrimSpace(fields)
// 拼接最终输出内容,添加颜色
if f.ForceColor {
coloredTimestamp := fmt.Sprintf("%s%s%s", colorGray, timestamp, resetColor)
coloredCaller := caller
if caller != "" {
coloredCaller = fmt.Sprintf("%s%s%s", colorPurple, caller, resetColor)
}
return []byte(fmt.Sprintf("%s%-5s%s[%s] [%s] %-20s | %s\n",
levelColor, level, resetColor, coloredTimestamp, fields, coloredCaller, entry.Message)), nil
}
return []byte(fmt.Sprintf("%-5s[%s] [%s] %-20s | %s\n",
level, timestamp, fields, caller, entry.Message)), nil
}
func getGoroutineID() string {
buf := make([]byte, 64)
buf = buf[:runtime.Stack(buf, false)]
// buf 格式: "goroutine 123 [running]:\n..."
i := 0
for i < len(buf) && buf[i] != ' ' {
i++
}
if i >= len(buf) {
return "0"
}
buf = buf[i+1:]
j := 0
for j < len(buf) && buf[j] != ' ' {
j++
}
return string(buf[:j])
}
// 初始化全局日志设置
func init() {
ConfigureFromEnv()
}
// ConfigureFromEnv 重新从环境变量应用日志配置。
// 这允许在 main() 中加载 .env 后,让 LOG_LEVEL / LOG_PATH 立即生效。
func ConfigureFromEnv() {
loggerMu.Lock()
defer loggerMu.Unlock()
if activeLogFile != nil {
_ = activeLogFile.Close()
activeLogFile = nil
}
// 根据环境变量设置全局日志级别
logLevel := getLogLevelFromEnv()
appLogger.SetLevel(logLevel)
writer := io.Writer(os.Stdout)
logPath := resolveLogPathFromEnv()
if logPath != "" {
file, err := openLogFile(logPath)
if err != nil {
fmt.Fprintf(os.Stderr, "logger: failed to open log file %s: %v\n", logPath, err)
} else {
activeLogFile = file
writer = io.MultiWriter(os.Stdout, &ansiStripWriter{w: file})
}
}
// 默认继续输出到 stdout,同时在可用时落盘到文件
appLogger.SetOutput(writer)
// 非终端(如 Docker 日志采集)禁用 ANSI 颜色,避免日志聚合/检索异常
forceColor := false
if fi, err := os.Stdout.Stat(); err == nil {
forceColor = (fi.Mode() & os.ModeCharDevice) != 0
}
// 设置日志格式而不修改全局时区
tmpl := resolveLogFormatFromEnv()
appLogger.SetFormatter(&CustomFormatter{
ForceColor: forceColor,
Template: tmpl,
threadNeeded: strings.Contains(tmpl, "%thread"),
})
appLogger.SetReportCaller(false)
}
// GetLogger 获取日志实例
func GetLogger(c context.Context) *logrus.Entry {
if logger := c.Value(types.LoggerContextKey); logger != nil {
return logger.(*logrus.Entry)
}
return logrus.NewEntry(appLogger)
}
// SetOutput overrides the internal logger's output destination.
// Intended for use in tests that need to capture and assert on log content
// (e.g. verifying secrets are not written out). Restore the original writer
// (usually os.Stdout) in a defer after the test.
func SetOutput(w io.Writer) {
loggerMu.Lock()
defer loggerMu.Unlock()
appLogger.SetOutput(w)
}
// SetLogLevel 设置日志级别
func SetLogLevel(level LogLevel) {
var logLevel logrus.Level
switch level {
case LevelDebug:
logLevel = logrus.DebugLevel
case LevelInfo:
logLevel = logrus.InfoLevel
case LevelWarn:
logLevel = logrus.WarnLevel
case LevelError:
logLevel = logrus.ErrorLevel
case LevelFatal:
logLevel = logrus.FatalLevel
default:
logLevel = logrus.InfoLevel
}
appLogger.SetLevel(logLevel)
}
// getLogLevelFromEnv 从环境变量读取日志级别配置
func getLogLevelFromEnv() logrus.Level {
// 从环境变量读取LOG_LEVEL配置
logLevelStr := strings.ToLower(os.Getenv("LOG_LEVEL"))
switch logLevelStr {
case "debug":
return logrus.DebugLevel
case "info":
return logrus.InfoLevel
case "warn", "warning":
return logrus.WarnLevel
case "error":
return logrus.ErrorLevel
case "fatal":
return logrus.FatalLevel
default:
return logrus.DebugLevel // 无效配置时使用默认值
}
}
func resolveLogPathFromEnv() string {
if logPath := strings.TrimSpace(os.Getenv("LOG_PATH")); logPath != "" {
return filepath.Clean(logPath)
}
return defaultMacAppLogPath()
}
// resolveLogFormatFromEnv 从环境变量 LOG_FORMAT 读取自定义日志格式模板。
// 为空则使用内置默认格式;非空则作为模板,支持占位符:
// %d=时间 %level=级别 %thread=goroutine %logger=caller %traceId=请求ID %msg=消息+结构化字段
func resolveLogFormatFromEnv() string {
return strings.TrimSpace(os.Getenv("LOG_FORMAT"))
}
func defaultMacAppLogPath() string {
execPath, err := os.Executable()
if err != nil || !strings.Contains(execPath, ".app/Contents/MacOS") {
return ""
}
homeDir, err := os.UserHomeDir()
if err != nil {
return ""
}
appName := "WeKnora Lite"
if idx := strings.Index(execPath, ".app/Contents/MacOS"); idx >= 0 {
bundleName := filepath.Base(execPath[:idx+4])
if trimmed := strings.TrimSuffix(bundleName, ".app"); trimmed != "" {
appName = trimmed
}
}
return filepath.Join(homeDir, "Library", "Logs", appName, appName+".log")
}
func openLogFile(logPath string) (io.WriteCloser, error) {
dir := filepath.Dir(logPath)
if dir != "." {
if err := os.MkdirAll(dir, 0o755); err != nil {
return nil, err
}
}
return &lumberjack.Logger{
Filename: logPath,
MaxSize: 50, // megabytes
MaxBackups: 3,
MaxAge: 28, // days
Compress: true,
}, nil
}
// 添加调用者字段
func addCaller(entry *logrus.Entry, skip int) *logrus.Entry {
pc, file, line, ok := runtime.Caller(skip)
if !ok {
return entry
}
shortFile := path.Base(file)
funcName := "unknown"
if fn := runtime.FuncForPC(pc); fn != nil {
// 只保留函数名,不带包路径(如 doSomething
fullName := path.Base(fn.Name())
parts := strings.Split(fullName, ".")
funcName = parts[len(parts)-1]
}
return entry.WithField("caller", fmt.Sprintf("%s:%d[%s]", shortFile, line, funcName))
}
// WithRequestID 在日志中添加请求ID
func WithRequestID(c context.Context, requestID string) context.Context {
return WithField(c, "request_id", requestID)
}
// WithField 向日志中添加一个字段
func WithField(c context.Context, key string, value interface{}) context.Context {
logger := GetLogger(c).WithField(key, value)
return context.WithValue(c, types.LoggerContextKey, logger)
}
// WithFields 向日志中添加多个字段
func WithFields(c context.Context, fields logrus.Fields) context.Context {
logger := GetLogger(c).WithFields(fields)
return context.WithValue(c, types.LoggerContextKey, logger)
}
// Debug 输出调试级别的日志
func Debug(c context.Context, args ...interface{}) {
addCaller(GetLogger(c), 2).Debug(args...)
}
// Debugf 使用格式化字符串输出调试级别的日志
func Debugf(c context.Context, format string, args ...interface{}) {
addCaller(GetLogger(c), 2).Debugf(format, args...)
}
// Info 输出信息级别的日志
func Info(c context.Context, args ...interface{}) {
addCaller(GetLogger(c), 2).Info(args...)
}
// Infof 使用格式化字符串输出信息级别的日志
func Infof(c context.Context, format string, args ...interface{}) {
addCaller(GetLogger(c), 2).Infof(format, args...)
}
// Warn 输出警告级别的日志
func Warn(c context.Context, args ...interface{}) {
addCaller(GetLogger(c), 2).Warn(args...)
}
// Warnf 使用格式化字符串输出警告级别的日志
func Warnf(c context.Context, format string, args ...interface{}) {
addCaller(GetLogger(c), 2).Warnf(format, args...)
}
// Fields aliases logrus.Fields so callers in other packages can use the
// short form `logger.Fields{...}` without importing logrus directly.
type Fields = logrus.Fields
// WarnWithFields emits a warning with structured fields. Use this for
// audit-relevant events (cross-tenant probes, invariant violations) so that
// log aggregators can index the tenant/resource identifiers without
// parsing free-form text. Format-string style (Warnf) is appropriate for
// low-stakes diagnostic messages.
func WarnWithFields(c context.Context, fields Fields, msg string) {
if fields == nil {
fields = Fields{}
}
addCaller(GetLogger(c), 2).WithFields(fields).Warn(msg)
}
// Error 输出错误级别的日志
func Error(c context.Context, args ...interface{}) {
addCaller(GetLogger(c), 2).Error(args...)
}
// Errorf 使用格式化字符串输出错误级别的日志
func Errorf(c context.Context, format string, args ...interface{}) {
addCaller(GetLogger(c), 2).Errorf(format, args...)
}
// ErrorWithFields 输出带有额外字段的错误级别日志
func ErrorWithFields(c context.Context, err error, fields logrus.Fields) {
if fields == nil {
fields = logrus.Fields{}
}
if err != nil {
fields["error"] = err.Error()
}
addCaller(GetLogger(c), 2).WithFields(fields).Error("发生错误")
}
// Fatal 输出致命级别的日志并退出程序
func Fatal(c context.Context, args ...interface{}) {
addCaller(GetLogger(c), 2).Fatal(args...)
}
// Fatalf 使用格式化字符串输出致命级别的日志并退出程序
func Fatalf(c context.Context, format string, args ...interface{}) {
addCaller(GetLogger(c), 2).Fatalf(format, args...)
}
// CloneContext 复制上下文中的关键信息到新上下文
func CloneContext(ctx context.Context) context.Context {
newCtx := context.Background()
for _, k := range []types.ContextKey{
types.LoggerContextKey,
types.TenantIDContextKey,
types.RequestIDContextKey,
types.TenantInfoContextKey,
types.UserIDContextKey,
types.UserContextKey,
types.PrincipalContextKey,
types.TenantAPIKeyScopeContextKey,
// TenantRoleContextKey: the caller's resolved role in the
// active tenant (PR 2 #1303). Must be propagated for the same
// reason as TenantIDContextKey — any handler that does
// `ctx := logger.CloneContext(c.Request.Context())` and then
// reads role via TenantRoleFromContext would otherwise see the
// type-zero TenantRole and fall back
// to Viewer, blocking even Owners.
types.TenantRoleContextKey,
types.SystemAdminContextKey,
types.LanguageContextKey,
types.SessionTenantIDContextKey,
types.EmbedQueryContextKey,
types.EmbedVisitorContextKey,
// Keep the Langfuse trace alive across CloneContext boundaries so
// LLM/Embedder/Reranker/VLM/ASR wrappers attach their generations
// to the same trace opened by GinMiddleware, instead of each call
// auto-creating its own orphan trace.
types.LangfuseTraceContextKey,
} {
if v := ctx.Value(k); v != nil {
newCtx = context.WithValue(newCtx, k, v)
}
}
return newCtx
}