feat: 实现日志追踪链路 #185

Merged
huanghaosheng merged 30 commits from feature/log-track into develop 2026-06-21 23:23:23 +08:00
Showing only changes of commit d430e6e5b2 - Show all commits

View File

@@ -61,11 +61,18 @@ graph TB
NODES["Eino Nodes"] NODES["Eino Nodes"]
end end
subgraph 存储层["存储层"]
PG["PostgreSQL<br/>session/user/message/scenario"]
REDIS["Redis<br/>session/cache/ratelimit"]
end
ID --> MW ID --> MW
CTX --> LOG CTX --> LOG
LOG --> HANDLER LOG --> HANDLER
LOG --> ADAPTER LOG --> ADAPTER
LOG --> NODES LOG --> NODES
LOG --> PG
LOG --> REDIS
MW --> REST MW --> REST
GINLOG --> REST GINLOG --> REST
WS --> LOG WS --> LOG
@@ -276,22 +283,35 @@ r.Use(logger.GinRecovery()) // 第三层panic 恢复
} }
``` ```
### WebSocket 查询链路 ### WebSocket 查询链路(含存储层)
```json ```json
// 1. 查询接收 // 1. 查询接收
{"level":"info", "trace_id":"01J5XXX", "session_id":"abc-123", "request_id":"req-456", "msg":"query received"} {"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} {"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} {"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} {"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 查询完整链路 ### 按 trace_id 查询完整链路
@@ -322,6 +342,25 @@ grep 'trace_id":"01J5XXX"' backend.log | jq -r '[.ts, .msg] | @tsv'
| latency_ms > 5000 | 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 ```logql
@@ -369,6 +408,111 @@ log.Debugw("stt recognition completed",
| 系统错误 | Error | `"database query failed"`, `"tts synthesis failed"` | | 系统错误 | Error | `"database query failed"`, `"tts synthesis failed"` |
| 严重故障 | Error + stack | `"panic recovered"` | | 严重故障 | 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. **日志语言**:统一使用英文 1. **日志语言**:统一使用英文
@@ -377,11 +521,12 @@ log.Debugw("stt recognition completed",
4. **敏感内容**:禁止在 Info 及以上级别记录用户文本原文 4. **敏感内容**:禁止在 Info 及以上级别记录用户文本原文
5. **错误日志**:采用"调用方记录"原则,底层函数 return wrapped error 5. **错误日志**:采用"调用方记录"原则,底层函数 return wrapped error
6. **级别约定** 6. **级别约定**
- `Debug`:内部状态跟踪、开发调试信息 - `Debug`:内部状态跟踪、开发调试信息(数据库/缓存成功操作)
- `Info`:请求/连接生命周期、关键操作里程碑 - `Info`:请求/连接生命周期、关键操作里程碑
- `Warn`可降级异常Redis 故障、限流触发) - `Warn`可降级异常Redis 故障、限流触发)
- `Error`:影响用户的操作失败 - `Error`:影响用户的操作失败数据库错误、Redis 连接失败)
- `Fatal`:仅启动阶段不可恢复错误 - `Fatal`:仅启动阶段不可恢复错误
7. **预期内的空结果**`pgx.ErrNoRows``redis.Nil` 等不记录错误日志
## 性能考量 ## 性能考量