diff --git a/docs/13-日志追踪.md b/docs/13-日志追踪.md index bd86bb9..b08d5c2 100644 --- a/docs/13-日志追踪.md +++ b/docs/13-日志追踪.md @@ -61,11 +61,18 @@ graph TB NODES["Eino Nodes"] end + subgraph 存储层["存储层"] + PG["PostgreSQL
session/user/message/scenario"] + REDIS["Redis
session/cache/ratelimit"] + end + ID --> MW CTX --> LOG LOG --> HANDLER LOG --> ADAPTER LOG --> NODES + LOG --> PG + LOG --> REDIS MW --> REST GINLOG --> REST WS --> LOG @@ -276,22 +283,35 @@ r.Use(logger.GinRecovery()) // 第三层:panic 恢复 } ``` -### WebSocket 查询链路 +### WebSocket 查询链路(含存储层) ```json // 1. 查询接收 {"level":"info", "trace_id":"01J5XXX", "session_id":"abc-123", "request_id":"req-456", "msg":"query received"} -// 2. STT 完成(Debug) +// 2. 会话加载(Redis) +{"level":"debug", "trace_id":"01J5XXX", "session_id":"abc-123", "request_id":"req-456", "msg":"redis session retrieved", "session_id":"abc-123"} + +// 3. STT 完成 {"level":"debug", "trace_id":"01J5XXX", "session_id":"abc-123", "request_id":"req-456", "msg":"stt recognition completed", "text_len":45} -// 3. LLM 完成 +// 4. LLM 完成 {"level":"info", "trace_id":"01J5XXX", "session_id":"abc-123", "request_id":"req-456", "msg":"llm generation completed", "tokens":150} -// 4. Pipeline 完成 +// 5. 消息持久化(PostgreSQL) +{"level":"debug", "trace_id":"01J5XXX", "session_id":"abc-123", "request_id":"req-456", "msg":"message saved", "role":"user", "tokens_used":45} +{"level":"debug", "trace_id":"01J5XXX", "session_id":"abc-123", "request_id":"req-456", "msg":"message saved", "role":"assistant", "tokens_used":150} + +// 6. Pipeline 完成 {"level":"info", "trace_id":"01J5XXX", "session_id":"abc-123", "request_id":"req-456", "msg":"query processing completed", "latency_ms":2340} ``` +### 限流触发场景 + +```json +{"level":"warn", "trace_id":"01J5YYY", "msg":"rate limit triggered", "key":"ratelimit:user-456:query", "retry_after_sec":2.5} +``` + ## 日志查询操作 ### 按 trace_id 查询完整链路 @@ -322,6 +342,25 @@ grep 'trace_id":"01J5XXX"' backend.log | jq -r '[.ts, .msg] | @tsv' | latency_ms > 5000 ``` +### 查询数据库错误 + +```logql +{app="camtalk-backend"} + | json + | level="error" + | msg=~".*failed" + | line_format "{{.trace_id}} {{.msg}} {{.error}}" +``` + +### 查询 Redis 降级事件 + +```logql +{app="camtalk-backend"} + | json + | level="warn" + | msg=~"redis.*failed" +``` + ### 查询错误率 ```logql @@ -369,6 +408,111 @@ log.Debugw("stt recognition completed", | 系统错误 | Error | `"database query failed"`, `"tts synthesis failed"` | | 严重故障 | Error + stack | `"panic recovered"` | +## 存储层日志实现 + +### PostgreSQL Repository 层 + +所有数据库操作统一使用 `trace.FromContext(ctx)` 记录日志: + +**已实现文件**: +- `backend/internal/store/session_pg.go` — 会话 CRUD +- `backend/internal/store/user_pg.go` — 用户与 refresh token 操作 +- `backend/internal/store/message_pg.go` — 对话消息存储 +- `backend/internal/store/user_scenario_repository.go` — 用户自定义情景 + +**日志策略**: + +```go +func (r *PgSessionRepository) Save(ctx context.Context, s SessionRecord) error { + log := trace.FromContext(ctx) + + _, err := r.pool.Exec(ctx, ...) + if err != nil { + log.Errorw("save session failed", "session_id", s.ID, "error", err) + return err + } + + log.Debugw("session saved", "session_id", s.ID, "user_id", s.UserID) + return nil +} +``` + +**NotFound 处理**:预期内的空结果不记录错误: + +```go +if errors.Is(err, pgx.ErrNoRows) { + return nil, ErrSessionNotFound // 不记录日志 +} +if err != nil { + log.Errorw("find session failed", "session_id", id, "error", err) + return nil, err +} +``` + +### Redis 服务层 + +**已实现文件**: +- `backend/internal/session/redis.go` — RedisManager(会话存储) +- `backend/internal/store/cached_user.go` — CachedUserRepository(用户缓存装饰器) +- `backend/internal/ratelimit/redis_bucket.go` — RedisLimiter(令牌桶限流器) + +**会话存储日志**(`redis.go`): + +```go +func (m *RedisManager) Get(ctx context.Context, sessionID string) (*models.Session, error) { + log := trace.FromContext(ctx) + + vals, err := m.rdb.HGetAll(ctx, metaKey(sessionID)).Result() + if err != nil { + log.Errorw("redis get session failed", "session_id", sessionID, "error", err) + return nil, fmt.Errorf("redis get session: %w", err) + } + + if len(vals) == 0 { + return nil, ErrSessionNotFound // 不记录日志 + } + + log.Debugw("redis session retrieved", "session_id", sessionID) + return session, nil +} +``` + +**缓存降级日志**(`cached_user.go`): + +```go +if _, err := pipe.Exec(ctx); err != nil { + log := trace.FromContext(ctx) + log.Warnw("redis cache write failed for refresh token", "error", err) + // 降级:DB 已写入成功,Redis 失败不影响正确性 +} +``` + +**限流触发日志**(`redis_bucket.go`): + +```go +func (l *RedisLimiter) Allow(ctx context.Context, key string) (bool, time.Duration) { + log := trace.FromContext(ctx) + + result, err := l.script.Run(ctx, ...).Result() + if err != nil { + log.Errorw("rate limit check failed", "key", key, "error", err) + return true, 0 // fail-open 策略 + } + + if allowed == 0 { + log.Warnw("rate limit triggered", "key", key, "retry_after_sec", retryAfterSec) + return false, retryAfter + } + + return true, 0 +} +``` + +**级别选择原则**: +- **Error**:Redis 连接失败、Lua 脚本执行失败(影响功能) +- **Warn**:缓存写入失败(可降级)、限流触发(预期内异常) +- **Debug**:正常操作完成(避免 Info 级别噪音) + ## 编码规范 1. **日志语言**:统一使用英文 @@ -377,11 +521,12 @@ log.Debugw("stt recognition completed", 4. **敏感内容**:禁止在 Info 及以上级别记录用户文本原文 5. **错误日志**:采用"调用方记录"原则,底层函数 return wrapped error 6. **级别约定**: - - `Debug`:内部状态跟踪、开发调试信息 + - `Debug`:内部状态跟踪、开发调试信息(数据库/缓存成功操作) - `Info`:请求/连接生命周期、关键操作里程碑 - `Warn`:可降级异常(Redis 故障、限流触发) - - `Error`:影响用户的操作失败 + - `Error`:影响用户的操作失败(数据库错误、Redis 连接失败) - `Fatal`:仅启动阶段不可恢复错误 +7. **预期内的空结果**:`pgx.ErrNoRows`、`redis.Nil` 等不记录错误日志 ## 性能考量