任务日志优化

This commit is contained in:
ryan
2026-06-11 16:54:45 +08:00
parent f14875a8de
commit 7da4b72d24
5 changed files with 340 additions and 125 deletions
+111 -5
View File
@@ -6,12 +6,14 @@ package model
import (
"context"
"errors"
"fmt"
"strings"
"time"
"github.com/Rain-kl/Wavelet/internal/db"
"github.com/Rain-kl/Wavelet/internal/db/idgen"
"gorm.io/gorm"
"github.com/redis/go-redis/v9"
)
// TaskExecutionStatus 任务执行状态
@@ -23,6 +25,10 @@ const (
TaskExecutionStatusRunning TaskExecutionStatus = "running"
TaskExecutionStatusSucceeded TaskExecutionStatus = "succeeded"
TaskExecutionStatusFailed TaskExecutionStatus = "failed"
taskExecutionLogRedisKeyPrefix = "task:execution:log:"
taskExecutionLogExpiration = 24 * time.Hour
taskExecutionLogMaxLines = 1000
)
// TaskExecution 任务执行记录
@@ -58,7 +64,7 @@ func CreateTaskExecution(ctx context.Context, execution *TaskExecution) error {
return db.DB(ctx).Create(execution).Error
}
// UpdateTaskExecution 更新任务执行记录,忽略 log 字段以防覆写正在追加的日志
// UpdateTaskExecution 更新任务执行记录,忽略由 Redis 缓冲和归档流程管理的 log 字段。
func UpdateTaskExecution(ctx context.Context, execution *TaskExecution) error {
return db.DB(ctx).Omit("log").Save(execution).Error
}
@@ -69,6 +75,9 @@ func GetTaskExecutionByTaskID(ctx context.Context, taskID string) (*TaskExecutio
if err := db.DB(ctx).Where("task_id = ?", taskID).First(&execution).Error; err != nil {
return nil, err
}
if err := loadTaskExecutionLog(ctx, &execution); err != nil {
return nil, err
}
return &execution, nil
}
@@ -78,16 +87,64 @@ func GetTaskExecutionByID(ctx context.Context, id uint64) (*TaskExecution, error
if err := db.DB(ctx).Where("id = ?", id).First(&execution).Error; err != nil {
return nil, err
}
if err := loadTaskExecutionLog(ctx, &execution); err != nil {
return nil, err
}
return &execution, nil
}
// AppendTaskExecutionLog 追加日志到执行记录
// AppendTaskExecutionLog 将日志追加到 Redis 缓冲,任务完成后再持久化到数据库。
func AppendTaskExecutionLog(ctx context.Context, taskID string, logLine string) error {
if db.Redis == nil {
return errors.New("redis client is not initialized")
}
now := time.Now().Format("15:04:05")
line := fmt.Sprintf("[%s] %s\n", now, logLine)
return db.DB(ctx).Model(&TaskExecution{}).
key := taskExecutionLogRedisKey(taskID)
_, err := db.Redis.TxPipelined(ctx, func(pipe redis.Pipeliner) error {
pipe.RPush(ctx, key, line)
pipe.LTrim(ctx, key, -taskExecutionLogMaxLines, -1)
pipe.Expire(ctx, key, taskExecutionLogExpiration)
return nil
})
if err != nil {
return fmt.Errorf("append task execution log to redis: %w", err)
}
return nil
}
// FlushTaskExecutionLog 将 Redis 中的完整任务日志写入数据库,并在成功后清理缓存。
func FlushTaskExecutionLog(ctx context.Context, taskID string) error {
if db.Redis == nil {
return errors.New("redis client is not initialized")
}
key := taskExecutionLogRedisKey(taskID)
logLines, err := db.Redis.LRange(ctx, key, 0, -1).Result()
if err != nil {
return fmt.Errorf("get task execution log from redis: %w", err)
}
if len(logLines) == 0 {
return nil
}
logText := strings.Join(logLines, "")
result := db.DB(ctx).Model(&TaskExecution{}).
Where("task_id = ?", taskID).
Update("log", gorm.Expr("COALESCE(log, '') || ?", line)).Error
Update("log", logText)
if result.Error != nil {
return fmt.Errorf("persist task execution log: %w", result.Error)
}
if result.RowsAffected == 0 {
return fmt.Errorf("persist task execution log: task %q not found", taskID)
}
if err := db.Redis.Del(ctx, key).Err(); err != nil {
return fmt.Errorf("delete persisted task execution log from redis: %w", err)
}
return nil
}
// ListTaskExecutionsRequest 查询任务执行记录列表请求
@@ -126,6 +183,55 @@ func ListTaskExecutions(ctx context.Context, req ListTaskExecutionsRequest) ([]T
if err := query.Order("id DESC").Offset(offset).Limit(req.PageSize).Find(&executions).Error; err != nil {
return nil, 0, err
}
if err := loadTaskExecutionLogs(ctx, executions); err != nil {
return nil, 0, err
}
return executions, total, nil
}
func taskExecutionLogRedisKey(taskID string) string {
return db.PrefixedKey(taskExecutionLogRedisKeyPrefix + taskID)
}
func loadTaskExecutionLog(ctx context.Context, execution *TaskExecution) error {
if db.Redis == nil {
return nil
}
logLines, err := db.Redis.LRange(ctx, taskExecutionLogRedisKey(execution.TaskID), 0, -1).Result()
if err != nil {
return fmt.Errorf("get task execution log from redis: %w", err)
}
if len(logLines) == 0 {
return nil
}
execution.Log = strings.Join(logLines, "")
return nil
}
func loadTaskExecutionLogs(ctx context.Context, executions []TaskExecution) error {
if db.Redis == nil || len(executions) == 0 {
return nil
}
commands := make([]*redis.StringSliceCmd, len(executions))
_, err := db.Redis.Pipelined(ctx, func(pipe redis.Pipeliner) error {
for i := range executions {
commands[i] = pipe.LRange(ctx, taskExecutionLogRedisKey(executions[i].TaskID), 0, -1)
}
return nil
})
if err != nil {
return fmt.Errorf("get task execution logs from redis: %w", err)
}
for i := range executions {
logLines := commands[i].Val()
if len(logLines) > 0 {
executions[i].Log = strings.Join(logLines, "")
}
}
return nil
}
+94 -9
View File
@@ -6,11 +6,14 @@ package model
import (
"context"
"fmt"
"testing"
"time"
"github.com/Rain-kl/Wavelet/internal/db"
"github.com/alicebob/miniredis/v2"
"github.com/glebarez/sqlite"
"github.com/redis/go-redis/v9"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"gorm.io/gorm"
@@ -25,10 +28,18 @@ func setupTaskExecutionTestEnvironment(t *testing.T) func() {
err = sqliteDB.AutoMigrate(&TaskExecution{})
require.NoError(t, err)
miniRedis, err := miniredis.Run()
require.NoError(t, err)
redisClient := redis.NewClient(&redis.Options{Addr: miniRedis.Addr()})
db.SetDB(sqliteDB)
db.Redis = redisClient
return func() {
require.NoError(t, redisClient.Close())
miniRedis.Close()
db.SetDB(nil)
db.Redis = nil
}
}
@@ -188,7 +199,7 @@ func TestUpdateTaskExecutionFailed(t *testing.T) {
assert.Equal(t, int64(200), found.Duration)
}
func TestUpdateTaskExecutionDoesNotOverwriteLog(t *testing.T) {
func TestUpdateTaskExecutionDoesNotPersistBufferedLog(t *testing.T) {
cleanup := setupTaskExecutionTestEnvironment(t)
defer cleanup()
ctx := context.Background()
@@ -203,23 +214,25 @@ func TestUpdateTaskExecutionDoesNotOverwriteLog(t *testing.T) {
err := CreateTaskExecution(ctx, execution)
require.NoError(t, err)
// In a real execution, logs are appended to the DB asynchronously via AppendTaskExecutionLog
// 运行中的日志仅缓存在 Redis。
err = AppendTaskExecutionLog(ctx, "test_omit_log_001", "第一条执行日志")
require.NoError(t, err)
// The local struct still has empty Log because it was not reloaded
assert.Empty(t, execution.Log)
// Now complete/update the execution (e.g. status, duration)
execution.Status = TaskExecutionStatusSucceeded
execution.Duration = 100
err = UpdateTaskExecution(ctx, execution)
require.NoError(t, err)
// Get the updated execution record and check that the Log was NOT overwritten/wiped
var persisted TaskExecution
err = db.DB(ctx).Where("task_id = ?", "test_omit_log_001").First(&persisted).Error
require.NoError(t, err)
assert.Equal(t, TaskExecutionStatusSucceeded, persisted.Status)
assert.Empty(t, persisted.Log)
found, err := GetTaskExecutionByTaskID(ctx, "test_omit_log_001")
require.NoError(t, err)
assert.Equal(t, TaskExecutionStatusSucceeded, found.Status)
assert.Contains(t, found.Log, "第一条执行日志")
}
@@ -248,12 +261,51 @@ func TestAppendTaskExecutionLog(t *testing.T) {
err = AppendTaskExecutionLog(ctx, "test_log_001", "清理完成,共删除 42 个文件")
require.NoError(t, err)
// 验证日志内容
// 读取时优先返回 Redis 中的在途日志。
found, err := GetTaskExecutionByTaskID(ctx, "test_log_001")
require.NoError(t, err)
assert.Contains(t, found.Log, "开始扫描未使用上传文件")
assert.Contains(t, found.Log, "本批次找到 42 个待清理文件")
assert.Contains(t, found.Log, "清理完成,共删除 42 个文件")
var persisted TaskExecution
err = db.DB(ctx).Where("task_id = ?", "test_log_001").First(&persisted).Error
require.NoError(t, err)
assert.Empty(t, persisted.Log)
err = FlushTaskExecutionLog(ctx, "test_log_001")
require.NoError(t, err)
err = db.DB(ctx).Where("task_id = ?", "test_log_001").First(&persisted).Error
require.NoError(t, err)
assert.Contains(t, persisted.Log, "开始扫描未使用上传文件")
exists, err := db.Redis.Exists(ctx, taskExecutionLogRedisKey("test_log_001")).Result()
require.NoError(t, err)
assert.Zero(t, exists)
}
func TestAppendTaskExecutionLogLimitsLinesAndRefreshesTTL(t *testing.T) {
cleanup := setupTaskExecutionTestEnvironment(t)
defer cleanup()
ctx := context.Background()
const taskID = "limited_log_001"
for i := 0; i < taskExecutionLogMaxLines+5; i++ {
err := AppendTaskExecutionLog(ctx, taskID, fmt.Sprintf("日志-%04d", i))
require.NoError(t, err)
}
key := taskExecutionLogRedisKey(taskID)
logLines, err := db.Redis.LRange(ctx, key, 0, -1).Result()
require.NoError(t, err)
assert.Len(t, logLines, taskExecutionLogMaxLines)
assert.Contains(t, logLines[0], "日志-0005")
assert.Contains(t, logLines[len(logLines)-1], "日志-1004")
ttl, err := db.Redis.TTL(ctx, key).Result()
require.NoError(t, err)
assert.Equal(t, taskExecutionLogExpiration, ttl)
}
func TestAppendTaskExecutionLogNonExistent(t *testing.T) {
@@ -261,10 +313,36 @@ func TestAppendTaskExecutionLogNonExistent(t *testing.T) {
defer cleanup()
ctx := context.Background()
// 对不存在的 TaskID 追加日志不应报错(COALESCE 处理空值)
// Redis 缓冲不依赖数据库记录是否已经创建。
err := AppendTaskExecutionLog(ctx, "nonexistent_task", "测试日志")
// SQLite 下 COALESCE + || 操作不应报错
assert.NoError(t, err)
err = FlushTaskExecutionLog(ctx, "nonexistent_task")
assert.Error(t, err)
}
func TestGetTaskExecutionLogPrefersRedis(t *testing.T) {
cleanup := setupTaskExecutionTestEnvironment(t)
defer cleanup()
ctx := context.Background()
execution := &TaskExecution{
TaskID: "redis_priority_001",
TaskType: "upload:cleanup_unused",
TaskName: "清理未使用上传",
Status: TaskExecutionStatusRunning,
Log: "数据库旧日志",
TriggeredBy: "manual",
}
err := CreateTaskExecution(ctx, execution)
require.NoError(t, err)
err = AppendTaskExecutionLog(ctx, execution.TaskID, "Redis 最新日志")
require.NoError(t, err)
found, err := GetTaskExecutionByID(ctx, execution.ID)
require.NoError(t, err)
assert.Contains(t, found.Log, "Redis 最新日志")
assert.NotContains(t, found.Log, "数据库旧日志")
}
func TestListTaskExecutions(t *testing.T) {
@@ -284,12 +362,19 @@ func TestListTaskExecutions(t *testing.T) {
err := CreateTaskExecution(ctx, r)
require.NoError(t, err)
}
err := AppendTaskExecutionLog(ctx, "list_004", "运行中的 Redis 日志")
require.NoError(t, err)
// 查询全部(分页)
items, total, err := ListTaskExecutions(ctx, ListTaskExecutionsRequest{Page: 1, PageSize: 10})
require.NoError(t, err)
assert.Equal(t, int64(5), total)
assert.Len(t, items, 5)
for _, item := range items {
if item.TaskID == "list_004" {
assert.Contains(t, item.Log, "运行中的 Redis 日志")
}
}
// 按状态筛选:failed
items, total, err = ListTaskExecutions(ctx, ListTaskExecutionsRequest{Status: "failed", Page: 1, PageSize: 10})
+24 -2
View File
@@ -128,7 +128,9 @@ func DispatchTask(ctx context.Context, taskType string, payload []byte, triggere
return "", fmt.Errorf(errTaskEnqueueFailed, err)
}
_ = model.AppendTaskExecutionLog(ctx, taskID, fmt.Sprintf("[系统] 任务已成功入队,等待调度执行 (队列: %s, 最大重试次数: %d)", meta.Queue, meta.MaxRetry))
if err := model.AppendTaskExecutionLog(ctx, taskID, fmt.Sprintf("[系统] 任务已成功入队,等待调度执行 (队列: %s, 最大重试次数: %d)", meta.Queue, meta.MaxRetry)); err != nil {
logger.ErrorF(ctx, "[TaskExecutor] 追加入队日志失败 taskID=%s: %v", taskID, err)
}
return taskID, nil
}
@@ -189,7 +191,9 @@ func RetryTask(ctx context.Context, id uint64) (string, error) {
return "", fmt.Errorf(errRetryTaskEnqueueFailed, err)
}
_ = model.AppendTaskExecutionLog(ctx, newTaskID, fmt.Sprintf("[系统] 手动触发重试,已重新创建任务并入队 (原任务ID: %s, 重试次数: %d/%d)", execution.TaskID, execution.RetryCount+1, execution.MaxRetry))
if err := model.AppendTaskExecutionLog(ctx, newTaskID, fmt.Sprintf("[系统] 手动触发重试,已重新创建任务并入队 (原任务ID: %s, 重试次数: %d/%d)", execution.TaskID, execution.RetryCount+1, execution.MaxRetry)); err != nil {
logger.ErrorF(ctx, "[TaskExecutor] 追加重试日志失败 taskID=%s: %v", newTaskID, err)
}
return newTaskID, nil
}
@@ -311,6 +315,24 @@ func completeTaskExecution(ctx context.Context, execution *model.TaskExecution,
if err := model.UpdateTaskExecution(ctx, execution); err != nil {
logger.ErrorF(ctx, "[TaskExecutor] 更新执行记录失败 taskID=%s: %v", execution.TaskID, err)
}
if shouldFlushTaskExecutionLog(ctx, execErr) {
if err := model.FlushTaskExecutionLog(ctx, execution.TaskID); err != nil {
logger.ErrorF(ctx, "[TaskExecutor] 持久化任务日志失败 taskID=%s: %v", execution.TaskID, err)
}
}
}
func shouldFlushTaskExecutionLog(ctx context.Context, execErr error) bool {
if execErr == nil {
return true
}
retryCount, hasRetryCount := asynq.GetRetryCount(ctx)
maxRetry, hasMaxRetry := asynq.GetMaxRetry(ctx)
if !hasRetryCount || !hasMaxRetry {
return true
}
return retryCount >= maxRetry
}
func handleFailedTask(ctx context.Context, execution *model.TaskExecution, t *asynq.Task, duration time.Duration, execErr error, span trace.Span) {
+38
View File
@@ -15,6 +15,7 @@ import (
"github.com/hibiken/asynq"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"go.opentelemetry.io/otel/trace"
)
// mockHandler 用于测试的模拟任务处理器
@@ -209,6 +210,43 @@ func TestProcessTaskFailure(t *testing.T) {
assert.Contains(t, found.Log, "开始执行任务")
}
func TestCompleteTaskExecutionFlushesLog(t *testing.T) {
cleanup := setupTest(t)
defer cleanup()
ctx := context.Background()
execution := &model.TaskExecution{
TaskID: "complete_flush_001",
TaskType: testTaskType,
TaskName: "测试任务",
Status: model.TaskExecutionStatusRunning,
TriggeredBy: "manual",
}
err := model.CreateTaskExecution(ctx, execution)
require.NoError(t, err)
ctx = withTaskID(ctx, execution.TaskID)
AppendLog(ctx, "任务执行中的日志")
finishTime := time.Now()
completeTaskExecution(
ctx,
execution,
asynq.NewTask(testTaskType, nil),
100*time.Millisecond,
finishTime,
&TaskResult{Message: "处理完成"},
nil,
trace.SpanFromContext(ctx),
)
found, err := model.GetTaskExecutionByTaskID(ctx, execution.TaskID)
require.NoError(t, err)
assert.Equal(t, model.TaskExecutionStatusSucceeded, found.Status)
assert.Contains(t, found.Log, "任务执行中的日志")
assert.Contains(t, found.Log, "任务执行成功")
}
func TestRetryTask(t *testing.T) {
cleanup := setupTest(t)
defer cleanup()