From 61beed67888d25a5ad88a80b8b9bf18a25c3bde9 Mon Sep 17 00:00:00 2001 From: Kerwin Date: Tue, 28 Oct 2025 11:07:00 +0800 Subject: [PATCH] =?UTF-8?q?update:=20=E6=97=A5=E5=BF=97=E4=BC=98=E5=8C=96?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- README.md | 5 + db/repo/cks_repository.go | 11 ++ db/repo/resource_repository.go | 11 +- db/repo/system_config_repository.go | 16 ++ db/repo/task_item_repository.go | 45 +++++- db/repo/task_repository.go | 111 ++++++++++++-- docs/logging.md | 132 +++++++++++++++++ env.example | 7 +- handlers/public_api_handler.go | 17 ++- handlers/system_config_handler.go | 8 + handlers/task_handler.go | 26 ++++ handlers/user_handler.go | 74 ++++++++++ main.go | 1 - middleware/auth.go | 28 ++-- task/expansion_processor.go | 188 +++++++++++++++++++++--- task/task_processor.go | 106 ++++++++++++-- task/transfer_processor.go | 63 +++++++- utils/logger.go | 217 ++++++++++++++++++++++++++-- 18 files changed, 991 insertions(+), 75 deletions(-) create mode 100644 docs/logging.md diff --git a/README.md b/README.md index ebb514b..973c41a 100644 --- a/README.md +++ b/README.md @@ -128,6 +128,11 @@ PORT=8080 # 时区配置 TIMEZONE=Asia/Shanghai + +# 日志配置 +LOG_LEVEL=INFO # 日志级别 (DEBUG, INFO, WARN, ERROR, FATAL) +DEBUG=false # 调试模式开关 +STRUCTURED_LOG=false # 结构化日志开关 (JSON格式) ``` --- diff --git a/db/repo/cks_repository.go b/db/repo/cks_repository.go index af40b3d..2da4b59 100644 --- a/db/repo/cks_repository.go +++ b/db/repo/cks_repository.go @@ -1,7 +1,10 @@ package repo import ( + "time" + "github.com/ctwj/urldb/db/entity" + "github.com/ctwj/urldb/utils" "gorm.io/gorm" ) @@ -66,20 +69,28 @@ func (r *CksRepositoryImpl) FindAll() ([]entity.Cks, error) { // FindByID 根据ID查找Cks，预加载Pan关联数据 func (r *CksRepositoryImpl) FindByID(id uint) (*entity.Cks, error) { + startTime := utils.GetCurrentTime() var cks entity.Cks err := r.db.Preload("Pan").First(&cks, id).Error + queryDuration := time.Since(startTime) if err != nil { + utils.Debug("FindByID失败: ID=%d, 错误=%v, 查询耗时=%v", id, err, queryDuration) return nil, err } + utils.Debug("FindByID成功: ID=%d, 查询耗时=%v", id, queryDuration) return &cks, nil } func (r *CksRepositoryImpl) FindByIds(ids []uint) ([]*entity.Cks, error) { + startTime := utils.GetCurrentTime() var cks []*entity.Cks err := r.db.Preload("Pan").Where("id IN ?", ids).Find(&cks).Error + queryDuration := time.Since(startTime) if err != nil { + utils.Debug("FindByIds失败: IDs数量=%d, 错误=%v, 查询耗时=%v", len(ids), err, queryDuration) return nil, err } + utils.Debug("FindByIds成功: 找到%d个账号，查询耗时=%v", len(cks), queryDuration) return cks, nil } diff --git a/db/repo/resource_repository.go b/db/repo/resource_repository.go index 28396b1..2a315fb 100644 --- a/db/repo/resource_repository.go +++ b/db/repo/resource_repository.go @@ -5,6 +5,7 @@ import ( "time" "github.com/ctwj/urldb/db/entity" + "github.com/ctwj/urldb/utils" "gorm.io/gorm" ) @@ -201,6 +202,7 @@ func (r *ResourceRepositoryImpl) SearchByPanID(query string, panID uint, page, l // SearchWithFilters 根据参数进行搜索 func (r *ResourceRepositoryImpl) SearchWithFilters(params map[string]interface{}) ([]entity.Resource, int64, error) { + startTime := utils.GetCurrentTime() var resources []entity.Resource var total int64 @@ -318,8 +320,11 @@ func (r *ResourceRepositoryImpl) SearchWithFilters(params map[string]interface{} offset := (page - 1) * pageSize // 获取分页数据，按更新时间倒序 + queryStart := utils.GetCurrentTime() err := db.Order("updated_at DESC").Offset(offset).Limit(pageSize).Find(&resources).Error - fmt.Printf("查询结果: 总数=%d, 当前页数据量=%d, pageSize=%d\n", total, len(resources), pageSize) + queryDuration := time.Since(queryStart) + totalDuration := time.Since(startTime) + utils.Debug("SearchWithFilters完成: 总数=%d, 当前页数据量=%d, 查询耗时=%v, 总耗时=%v", total, len(resources), queryDuration, totalDuration) return resources, total, err } @@ -452,11 +457,15 @@ func (r *ResourceRepositoryImpl) GetResourcesForTransfer(panID uint, sinceTime t // GetByURL 根据URL获取资源 func (r *ResourceRepositoryImpl) GetByURL(url string) (*entity.Resource, error) { + startTime := utils.GetCurrentTime() var resource entity.Resource err := r.db.Where("url = ?", url).First(&resource).Error + queryDuration := time.Since(startTime) if err != nil { + utils.Debug("GetByURL失败: URL=%s, 错误=%v, 查询耗时=%v", url, err, queryDuration) return nil, err } + utils.Debug("GetByURL成功: URL=%s, 查询耗时=%v", url, queryDuration) return &resource, nil } diff --git a/db/repo/system_config_repository.go b/db/repo/system_config_repository.go index f22ac77..781e16b 100644 --- a/db/repo/system_config_repository.go +++ b/db/repo/system_config_repository.go @@ -3,6 +3,7 @@ package repo import ( "fmt" "sync" + "time" "github.com/ctwj/urldb/db/entity" "github.com/ctwj/urldb/utils" @@ -100,8 +101,11 @@ func (r *SystemConfigRepositoryImpl) UpsertConfigs(configs []entity.SystemConfig // GetOrCreateDefault 获取配置或创建默认配置 func (r *SystemConfigRepositoryImpl) GetOrCreateDefault() ([]entity.SystemConfig, error) { + startTime := utils.GetCurrentTime() configs, err := r.FindAll() + initialQueryDuration := time.Since(startTime) if err != nil { + utils.Error("获取所有系统配置失败: %v，耗时: %v", err, initialQueryDuration) return nil, err } @@ -141,11 +145,16 @@ func (r *SystemConfigRepositoryImpl) GetOrCreateDefault() ([]entity.SystemConfig {Key: entity.ConfigKeyQrCodeStyle, Value: entity.ConfigDefaultQrCodeStyle, Type: entity.ConfigTypeString}, } + createStart := utils.GetCurrentTime() err = r.UpsertConfigs(defaultConfigs) + createDuration := time.Since(createStart) if err != nil { + utils.Error("创建默认系统配置失败: %v，耗时: %v", err, createDuration) return nil, err } + totalDuration := time.Since(startTime) + utils.Info("创建默认系统配置成功，数量: %d，总耗时: %v", len(defaultConfigs), totalDuration) return defaultConfigs, nil } @@ -198,17 +207,24 @@ func (r *SystemConfigRepositoryImpl) GetOrCreateDefault() ([]entity.SystemConfig // 如果有缺失的配置项，则添加它们 if len(missingConfigs) > 0 { + upsertStart := utils.GetCurrentTime() err = r.UpsertConfigs(missingConfigs) + upsertDuration := time.Since(upsertStart) if err != nil { + utils.Error("添加缺失的系统配置失败: %v，耗时: %v", err, upsertDuration) return nil, err } + utils.Debug("添加缺失的系统配置完成，数量: %d，耗时: %v", len(missingConfigs), upsertDuration) // 重新获取所有配置 configs, err = r.FindAll() if err != nil { + utils.Error("重新获取所有系统配置失败: %v", err) return nil, err } } + totalDuration := time.Since(startTime) + utils.Debug("GetOrCreateDefault完成，总数: %d，总耗时: %v", len(configs), totalDuration) return configs, nil } diff --git a/db/repo/task_item_repository.go b/db/repo/task_item_repository.go index c6febf0..06fff78 100644 --- a/db/repo/task_item_repository.go +++ b/db/repo/task_item_repository.go @@ -1,7 +1,10 @@ package repo import ( + "time" + "github.com/ctwj/urldb/db/entity" + "github.com/ctwj/urldb/utils" "gorm.io/gorm" ) @@ -58,8 +61,15 @@ func (r *TaskItemRepositoryImpl) DeleteByTaskID(taskID uint) error { // GetByTaskIDAndStatus 根据任务ID和状态获取任务项 func (r *TaskItemRepositoryImpl) GetByTaskIDAndStatus(taskID uint, status string) ([]*entity.TaskItem, error) { + startTime := utils.GetCurrentTime() var items []*entity.TaskItem err := r.db.Where("task_id = ? AND status = ?", taskID, status).Order("id ASC").Find(&items).Error + queryDuration := time.Since(startTime) + if err != nil { + utils.Error("GetByTaskIDAndStatus失败: 任务ID=%d, 状态=%s, 错误=%v, 查询耗时=%v", taskID, status, err, queryDuration) + return nil, err + } + utils.Debug("GetByTaskIDAndStatus成功: 任务ID=%d, 状态=%s, 数量=%d, 查询耗时=%v", taskID, status, len(items), queryDuration) return items, err } @@ -93,19 +103,36 @@ func (r *TaskItemRepositoryImpl) GetListByTaskID(taskID uint, page, pageSize int // UpdateStatus 更新任务项状态 func (r *TaskItemRepositoryImpl) UpdateStatus(id uint, status string) error { - return r.db.Model(&entity.TaskItem{}).Where("id = ?", id).Update("status", status).Error + startTime := utils.GetCurrentTime() + err := r.db.Model(&entity.TaskItem{}).Where("id = ?", id).Update("status", status).Error + updateDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateStatus失败: ID=%d, 状态=%s, 错误=%v, 更新耗时=%v", id, status, err, updateDuration) + return err + } + utils.Debug("UpdateStatus成功: ID=%d, 状态=%s, 更新耗时=%v", id, status, updateDuration) + return nil } // UpdateStatusAndOutput 更新任务项状态和输出数据 func (r *TaskItemRepositoryImpl) UpdateStatusAndOutput(id uint, status, outputData string) error { - return r.db.Model(&entity.TaskItem{}).Where("id = ?", id).Updates(map[string]interface{}{ + startTime := utils.GetCurrentTime() + err := r.db.Model(&entity.TaskItem{}).Where("id = ?", id).Updates(map[string]interface{}{ "status": status, "output_data": outputData, }).Error + updateDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateStatusAndOutput失败: ID=%d, 状态=%s, 错误=%v, 更新耗时=%v", id, status, err, updateDuration) + return err + } + utils.Debug("UpdateStatusAndOutput成功: ID=%d, 状态=%s, 更新耗时=%v", id, status, updateDuration) + return nil } // GetStatsByTaskID 获取任务项统计信息 func (r *TaskItemRepositoryImpl) GetStatsByTaskID(taskID uint) (map[string]int, error) { + startTime := utils.GetCurrentTime() var results []struct { Status string Count int @@ -117,7 +144,9 @@ func (r *TaskItemRepositoryImpl) GetStatsByTaskID(taskID uint) (map[string]int, Group("status"). Find(&results).Error + queryDuration := time.Since(startTime) if err != nil { + utils.Error("GetStatsByTaskID失败: 任务ID=%d, 错误=%v, 查询耗时=%v", taskID, err, queryDuration) return nil, err } @@ -134,12 +163,22 @@ func (r *TaskItemRepositoryImpl) GetStatsByTaskID(taskID uint) (map[string]int, stats["total"] += result.Count } + totalDuration := time.Since(startTime) + utils.Debug("GetStatsByTaskID成功: 任务ID=%d, 统计信息=%v, 查询耗时=%v, 总耗时=%v", taskID, stats, queryDuration, totalDuration) return stats, nil } // ResetProcessingItems 重置处理中的任务项为pending状态 func (r *TaskItemRepositoryImpl) ResetProcessingItems(taskID uint) error { - return r.db.Model(&entity.TaskItem{}). + startTime := utils.GetCurrentTime() + err := r.db.Model(&entity.TaskItem{}). Where("task_id = ? AND status = ?", taskID, "processing"). Update("status", "pending").Error + updateDuration := time.Since(startTime) + if err != nil { + utils.Error("ResetProcessingItems失败: 任务ID=%d, 错误=%v, 更新耗时=%v", taskID, err, updateDuration) + return err + } + utils.Debug("ResetProcessingItems成功: 任务ID=%d, 更新耗时=%v", taskID, updateDuration) + return nil } diff --git a/db/repo/task_repository.go b/db/repo/task_repository.go index f3a0a69..287ff1b 100644 --- a/db/repo/task_repository.go +++ b/db/repo/task_repository.go @@ -4,6 +4,7 @@ import ( "time" "github.com/ctwj/urldb/db/entity" + "github.com/ctwj/urldb/utils" "gorm.io/gorm" ) @@ -35,11 +36,15 @@ func NewTaskRepository(db *gorm.DB) TaskRepository { // GetByID 根据ID获取任务 func (r *TaskRepositoryImpl) GetByID(id uint) (*entity.Task, error) { + startTime := utils.GetCurrentTime() var task entity.Task err := r.db.First(&task, id).Error + queryDuration := time.Since(startTime) if err != nil { + utils.Debug("GetByID失败: ID=%d, 错误=%v, 查询耗时=%v", id, err, queryDuration) return nil, err } + utils.Debug("GetByID成功: ID=%d, 查询耗时=%v", id, queryDuration) return &task, nil } @@ -55,6 +60,7 @@ func (r *TaskRepositoryImpl) Delete(id uint) error { // GetList 获取任务列表 func (r *TaskRepositoryImpl) GetList(page, pageSize int, taskType, status string) ([]*entity.Task, int64, error) { + startTime := utils.GetCurrentTime() var tasks []*entity.Task var total int64 @@ -69,84 +75,171 @@ func (r *TaskRepositoryImpl) GetList(page, pageSize int, taskType, status string } // 获取总数 + countStart := utils.GetCurrentTime() err := query.Count(&total).Error + countDuration := time.Since(countStart) if err != nil { + utils.Error("GetList获取总数失败: 错误=%v, 查询耗时=%v", err, countDuration) return nil, 0, err } // 分页查询 offset := (page - 1) * pageSize + queryStart := utils.GetCurrentTime() err = query.Offset(offset).Limit(pageSize).Order("created_at DESC").Find(&tasks).Error + queryDuration := time.Since(queryStart) if err != nil { + utils.Error("GetList查询失败: 错误=%v, 查询耗时=%v", err, queryDuration) return nil, 0, err } + totalDuration := time.Since(startTime) + utils.Debug("GetList完成: 任务类型=%s, 状态=%s, 页码=%d, 页面大小=%d, 总数=%d, 结果数=%d, 总耗时=%v", taskType, status, page, pageSize, total, len(tasks), totalDuration) return tasks, total, nil } // UpdateStatus 更新任务状态 func (r *TaskRepositoryImpl) UpdateStatus(id uint, status string) error { - return r.db.Model(&entity.Task{}).Where("id = ?", id).Update("status", status).Error + startTime := utils.GetCurrentTime() + err := r.db.Model(&entity.Task{}).Where("id = ?", id).Update("status", status).Error + updateDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateStatus失败: ID=%d, 状态=%s, 错误=%v, 更新耗时=%v", id, status, err, updateDuration) + return err + } + utils.Debug("UpdateStatus成功: ID=%d, 状态=%s, 更新耗时=%v", id, status, updateDuration) + return nil } // UpdateProgress 更新任务进度 func (r *TaskRepositoryImpl) UpdateProgress(id uint, progress float64, progressData string) error { + startTime := utils.GetCurrentTime() // 检查progress和progress_data字段是否存在 var count int64 err := r.db.Raw("SELECT COUNT(*) FROM information_schema.columns WHERE table_name = 'tasks' AND column_name = 'progress'").Count(&count).Error if err != nil || count == 0 { // 如果检查失败或字段不存在，只更新processed_items等现有字段 - return r.db.Model(&entity.Task{}).Where("id = ?", id).Updates(map[string]interface{}{ + updateStart := utils.GetCurrentTime() + err := r.db.Model(&entity.Task{}).Where("id = ?", id).Updates(map[string]interface{}{ "processed_items": progress, // 使用progress作为processed_items的近似值 }).Error + updateDuration := time.Since(updateStart) + totalDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateProgress失败(字段不存在): ID=%d, 进度=%f, 错误=%v, 更新耗时=%v, 总耗时=%v", id, progress, err, updateDuration, totalDuration) + return err + } + utils.Debug("UpdateProgress成功(字段不存在): ID=%d, 进度=%f, 更新耗时=%v, 总耗时=%v", id, progress, updateDuration, totalDuration) + return nil } // 字段存在，正常更新 - return r.db.Model(&entity.Task{}).Where("id = ?", id).Updates(map[string]interface{}{ + updateStart := utils.GetCurrentTime() + err = r.db.Model(&entity.Task{}).Where("id = ?", id).Updates(map[string]interface{}{ "progress": progress, "progress_data": progressData, }).Error + updateDuration := time.Since(updateStart) + totalDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateProgress失败: ID=%d, 进度=%f, 错误=%v, 更新耗时=%v, 总耗时=%v", id, progress, err, updateDuration, totalDuration) + return err + } + utils.Debug("UpdateProgress成功: ID=%d, 进度=%f, 更新耗时=%v, 总耗时=%v", id, progress, updateDuration, totalDuration) + return nil } // UpdateStatusAndMessage 更新任务状态和消息 func (r *TaskRepositoryImpl) UpdateStatusAndMessage(id uint, status, message string) error { + startTime := utils.GetCurrentTime() // 检查message字段是否存在 var count int64 err := r.db.Raw("SELECT COUNT(*) FROM information_schema.columns WHERE table_name = 'tasks' AND column_name = 'message'").Count(&count).Error if err != nil { // 如果检查失败，只更新状态 - return r.db.Model(&entity.Task{}).Where("id = ?", id).Update("status", status).Error + updateStart := utils.GetCurrentTime() + err := r.db.Model(&entity.Task{}).Where("id = ?", id).Update("status", status).Error + updateDuration := time.Since(updateStart) + totalDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateStatusAndMessage失败(检查失败): ID=%d, 状态=%s, 错误=%v, 更新耗时=%v, 总耗时=%v", id, status, err, updateDuration, totalDuration) + return err + } + utils.Debug("UpdateStatusAndMessage成功(检查失败): ID=%d, 状态=%s, 更新耗时=%v, 总耗时=%v", id, status, updateDuration, totalDuration) + return nil } if count > 0 { // message字段存在，更新状态和消息 - return r.db.Model(&entity.Task{}).Where("id = ?", id).Updates(map[string]interface{}{ + updateStart := utils.GetCurrentTime() + err := r.db.Model(&entity.Task{}).Where("id = ?", id).Updates(map[string]interface{}{ "status": status, "message": message, }).Error + updateDuration := time.Since(updateStart) + totalDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateStatusAndMessage失败(字段存在): ID=%d, 状态=%s, 错误=%v, 更新耗时=%v, 总耗时=%v", id, status, err, updateDuration, totalDuration) + return err + } + utils.Debug("UpdateStatusAndMessage成功(字段存在): ID=%d, 状态=%s, 更新耗时=%v, 总耗时=%v", id, status, updateDuration, totalDuration) + return nil } else { // message字段不存在，只更新状态 - return r.db.Model(&entity.Task{}).Where("id = ?", id).Update("status", status).Error + updateStart := utils.GetCurrentTime() + err := r.db.Model(&entity.Task{}).Where("id = ?", id).Update("status", status).Error + updateDuration := time.Since(updateStart) + totalDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateStatusAndMessage失败(字段不存在): ID=%d, 状态=%s, 错误=%v, 更新耗时=%v, 总耗时=%v", id, status, err, updateDuration, totalDuration) + return err + } + utils.Debug("UpdateStatusAndMessage成功(字段不存在): ID=%d, 状态=%s, 更新耗时=%v, 总耗时=%v", id, status, updateDuration, totalDuration) + return nil } } // UpdateTaskStats 更新任务统计信息 func (r *TaskRepositoryImpl) UpdateTaskStats(id uint, processed, success, failed int) error { - return r.db.Model(&entity.Task{}).Where("id = ?", id).Updates(map[string]interface{}{ + startTime := utils.GetCurrentTime() + err := r.db.Model(&entity.Task{}).Where("id = ?", id).Updates(map[string]interface{}{ "processed_items": processed, "success_items": success, "failed_items": failed, }).Error + updateDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateTaskStats失败: ID=%d, 处理数=%d, 成功数=%d, 失败数=%d, 错误=%v, 更新耗时=%v", id, processed, success, failed, err, updateDuration) + return err + } + utils.Debug("UpdateTaskStats成功: ID=%d, 处理数=%d, 成功数=%d, 失败数=%d, 更新耗时=%v", id, processed, success, failed, updateDuration) + return nil } // UpdateStartedAt 更新任务开始时间 func (r *TaskRepositoryImpl) UpdateStartedAt(id uint) error { + startTime := utils.GetCurrentTime() now := time.Now() - return r.db.Model(&entity.Task{}).Where("id = ?", id).Update("started_at", now).Error + err := r.db.Model(&entity.Task{}).Where("id = ?", id).Update("started_at", now).Error + updateDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateStartedAt失败: ID=%d, 错误=%v, 更新耗时=%v", id, err, updateDuration) + return err + } + utils.Debug("UpdateStartedAt成功: ID=%d, 更新耗时=%v", id, updateDuration) + return nil } // UpdateCompletedAt 更新任务完成时间 func (r *TaskRepositoryImpl) UpdateCompletedAt(id uint) error { + startTime := utils.GetCurrentTime() now := time.Now() - return r.db.Model(&entity.Task{}).Where("id = ?", id).Update("completed_at", now).Error + err := r.db.Model(&entity.Task{}).Where("id = ?", id).Update("completed_at", now).Error + updateDuration := time.Since(startTime) + if err != nil { + utils.Error("UpdateCompletedAt失败: ID=%d, 错误=%v, 更新耗时=%v", id, err, updateDuration) + return err + } + utils.Debug("UpdateCompletedAt成功: ID=%d, 更新耗时=%v", id, updateDuration) + return nil } diff --git a/docs/logging.md b/docs/logging.md new file mode 100644 index 0000000..1861665 --- /dev/null +++ b/docs/logging.md @@ -0,0 +1,132 @@ +# 日志系统说明 + +## 概述 + +本项目使用自定义的日志系统，支持多种日志级别、环境差异化配置和结构化日志记录。 + +## 日志级别 + +日志系统支持以下级别（按严重程度递增）： + +1. **DEBUG** - 调试信息，用于开发和故障排除 +2. **INFO** - 一般信息，记录系统正常运行状态 +3. **WARN** - 警告信息，表示可能的问题但不影响系统运行 +4. **ERROR** - 错误信息，表示系统错误但可以继续运行 +5. **FATAL** - 致命错误，系统将退出 + +## 环境配置 + +### 日志级别配置 + +可以通过环境变量配置日志级别： + +```bash +# 设置日志级别（DEBUG, INFO, WARN, ERROR, FATAL） +LOG_LEVEL=DEBUG + +# 或者启用调试模式（等同于DEBUG级别） +DEBUG=true +``` + +默认情况下，开发环境使用DEBUG级别，生产环境使用INFO级别。 + +### 结构化日志 + +可以通过环境变量启用结构化日志（JSON格式）： + +```bash +# 启用结构化日志 +STRUCTURED_LOG=true +``` + +## 使用方法 + +### 基本日志记录 + +```go +import "github.com/ctwj/urldb/utils" + +// 基本日志记录 +utils.Debug("调试信息: %s", debugInfo) +utils.Info("一般信息: %s", info) +utils.Warn("警告信息: %s", warning) +utils.Error("错误信息: %s", err) +utils.Fatal("致命错误: %s", fatalErr) // 程序将退出 +``` + +### 结构化日志记录 + +结构化日志允许添加额外的字段信息，便于日志分析： + +```go +// 带字段的结构化日志 +utils.DebugWithFields(map[string]interface{}{ + "user_id": 123, + "action": "login", + "ip": "192.168.1.1", +}, "用户登录调试信息") + +utils.InfoWithFields(map[string]interface{}{ + "task_id": 456, + "status": "completed", + "duration_ms": 1250, +}, "任务处理完成") + +utils.ErrorWithFields(map[string]interface{}{ + "error_code": 500, + "error": "database connection failed", + "component": "database", +}, "数据库连接失败: %v", err) +``` + +## 日志输出 + +日志默认输出到： +- 控制台（标准输出） +- 文件（logs目录下的app_日期.log文件） + +日志文件支持轮转，单个文件最大100MB，最多保留5个备份文件，日志文件最长保留30天。 + +## 最佳实践 + +1. **选择合适的日志级别**： + - DEBUG：详细的调试信息，仅在开发和故障排除时使用 + - INFO：重要的业务流程和状态变更 + - WARN：可预期的问题和异常情况 + - ERROR：系统错误和异常 + - FATAL：系统无法继续运行的致命错误 + +2. **使用结构化日志**： + - 对于需要后续分析的日志，使用结构化日志 + - 添加有意义的字段，如用户ID、任务ID、请求ID等 + - 避免在字段中包含敏感信息 + +3. **性能监控**： + - 记录关键操作的执行时间 + - 使用duration_ms字段记录毫秒级耗时 + +4. **安全日志**： + - 记录所有认证和授权相关的操作 + - 包含客户端IP和用户信息 + - 记录失败的访问尝试 + +## 示例 + +```go +// 性能监控示例 +startTime := time.Now() +// 执行操作... +duration := time.Since(startTime) +utils.DebugWithFields(map[string]interface{}{ + "operation": "database_query", + "duration_ms": duration.Milliseconds(), +}, "数据库查询完成，耗时: %v", duration) + +// 安全日志示例 +utils.InfoWithFields(map[string]interface{}{ + "user_id": userID, + "ip": clientIP, + "action": "login", + "status": "success", +}, "用户登录成功 - 用户ID: %d, IP: %s", userID, clientIP) +``` \ No newline at end of file diff --git a/env.example b/env.example index b86bf6a..e1d0f2c 100644 --- a/env.example +++ b/env.example @@ -14,4 +14,9 @@ TIMEZONE=Asia/Shanghai # 文件上传配置 UPLOAD_DIR=./uploads -MAX_FILE_SIZE=5MB \ No newline at end of file +MAX_FILE_SIZE=5MB + +# 日志配置 +LOG_LEVEL=INFO # 日志级别 (DEBUG, INFO, WARN, ERROR, FATAL) +DEBUG=false # 调试模式开关 +STRUCTURED_LOG=false \ No newline at end of file diff --git a/handlers/public_api_handler.go b/handlers/public_api_handler.go index f7049be..d8fb1ef 100644 --- a/handlers/public_api_handler.go +++ b/handlers/public_api_handler.go @@ -148,6 +148,11 @@ func (h *PublicAPIHandler) AddBatchResources(c *gin.Context) { return } + // 记录API访问安全日志 + clientIP := c.ClientIP() + userAgent := c.GetHeader("User-Agent") + utils.Info("PublicAPI.AddBatchResources - API访问 - IP: %s, UserAgent: %s, 资源数量: %d", clientIP, userAgent, len(req.Resources)) + // 收集所有待提交的URL，去重 urlSet := make(map[string]struct{}) for _, resource := range req.Resources { @@ -238,7 +243,9 @@ func (h *PublicAPIHandler) AddBatchResources(c *gin.Context) { func (h *PublicAPIHandler) SearchResources(c *gin.Context) { startTime := time.Now() - // 获取查询参数 + // 记录API访问安全日志 + clientIP := c.ClientIP() + userAgent := c.GetHeader("User-Agent") keyword := c.Query("keyword") tag := c.Query("tag") category := c.Query("category") @@ -246,6 +253,9 @@ func (h *PublicAPIHandler) SearchResources(c *gin.Context) { pageStr := c.DefaultQuery("page", "1") pageSizeStr := c.DefaultQuery("page_size", "20") + utils.Info("PublicAPI.SearchResources - API访问 - IP: %s, UserAgent: %s, Keyword: %s, Tag: %s, Category: %s, PanID: %s", + clientIP, userAgent, keyword, tag, category, panID) + page, err := strconv.Atoi(pageStr) if err != nil || page < 1 { page = 1 @@ -402,9 +412,14 @@ func (h *PublicAPIHandler) SearchResources(c *gin.Context) { func (h *PublicAPIHandler) GetHotDramas(c *gin.Context) { startTime := time.Now() + // 记录API访问安全日志 + clientIP := c.ClientIP() + userAgent := c.GetHeader("User-Agent") pageStr := c.DefaultQuery("page", "1") pageSizeStr := c.DefaultQuery("page_size", "20") + utils.Info("PublicAPI.GetHotDramas - API访问 - IP: %s, UserAgent: %s", clientIP, userAgent) + page, err := strconv.Atoi(pageStr) if err != nil || page < 1 { page = 1 diff --git a/handlers/system_config_handler.go b/handlers/system_config_handler.go index 2ce4b85..474f7f9 100644 --- a/handlers/system_config_handler.go +++ b/handlers/system_config_handler.go @@ -130,6 +130,10 @@ func UpdateSystemConfig(c *gin.Context) { return } + adminUsername, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("UpdateSystemConfig - 管理员更新系统配置 - 管理员: %s, IP: %s", adminUsername, clientIP) + // 调试信息 utils.Info("接收到的配置请求: %+v", req) @@ -320,6 +324,10 @@ func ToggleAutoProcess(c *gin.Context) { return } + adminUsername, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("ToggleAutoProcess - 管理员切换自动处理配置 - 管理员: %s, 启用: %t, IP: %s", adminUsername, req.AutoProcessReadyResources, clientIP) + // 获取当前配置 configs, err := repoManager.SystemConfigRepository.GetOrCreateDefault() if err != nil { diff --git a/handlers/task_handler.go b/handlers/task_handler.go index 66990b6..37333d0 100644 --- a/handlers/task_handler.go +++ b/handlers/task_handler.go @@ -51,6 +51,10 @@ func (h *TaskHandler) CreateBatchTransferTask(c *gin.Context) { return } + username, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("CreateBatchTransferTask - 用户创建批量转存任务 - 用户: %s, 任务标题: %s, 资源数量: %d, IP: %s", username, req.Title, len(req.Resources), clientIP) + utils.Debug("创建批量转存任务: %s，资源数量: %d，选择账号数量: %d", req.Title, len(req.Resources), len(req.SelectedAccounts)) // 构建任务配置 @@ -124,6 +128,10 @@ func (h *TaskHandler) StartTask(c *gin.Context) { return } + username, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("StartTask - 用户启动任务 - 用户: %s, 任务ID: %d, IP: %s", username, taskID, clientIP) + err = h.taskManager.StartTask(uint(taskID)) if err != nil { utils.Error("启动任务失败: %v", err) @@ -147,6 +155,10 @@ func (h *TaskHandler) StopTask(c *gin.Context) { return } + username, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("StopTask - 用户停止任务 - 用户: %s, 任务ID: %d, IP: %s", username, taskID, clientIP) + err = h.taskManager.StopTask(uint(taskID)) if err != nil { utils.Error("停止任务失败: %v", err) @@ -170,6 +182,10 @@ func (h *TaskHandler) PauseTask(c *gin.Context) { return } + username, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("PauseTask - 用户暂停任务 - 用户: %s, 任务ID: %d, IP: %s", username, taskID, clientIP) + err = h.taskManager.PauseTask(uint(taskID)) if err != nil { utils.Error("暂停任务失败: %v", err) @@ -360,8 +376,13 @@ func (h *TaskHandler) DeleteTask(c *gin.Context) { return } + username, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("DeleteTask - 用户删除任务 - 用户: %s, 任务ID: %d, IP: %s", username, taskID, clientIP) + // 检查任务是否在运行 if h.taskManager.IsTaskRunning(uint(taskID)) { + utils.Warn("DeleteTask - 尝试删除正在运行的任务 - 用户: %s, 任务ID: %d, IP: %s", username, taskID, clientIP) ErrorResponse(c, "任务正在运行中，无法删除", http.StatusBadRequest) return } @@ -383,6 +404,7 @@ func (h *TaskHandler) DeleteTask(c *gin.Context) { } utils.Debug("任务删除成功: %d", taskID) + utils.Info("DeleteTask - 任务删除成功 - 用户: %s, 任务ID: %d, IP: %s", username, taskID, clientIP) SuccessResponse(c, gin.H{ "message": "任务删除成功", @@ -402,6 +424,10 @@ func (h *TaskHandler) CreateExpansionTask(c *gin.Context) { return } + username, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("CreateExpansionTask - 用户创建扩容任务 - 用户: %s, 账号ID: %d, IP: %s", username, req.PanAccountID, clientIP) + utils.Debug("创建扩容任务: 账号ID %d", req.PanAccountID) // 获取账号信息，用于构建任务标题 diff --git a/handlers/user_handler.go b/handlers/user_handler.go index 4a7b9c9..b292538 100644 --- a/handlers/user_handler.go +++ b/handlers/user_handler.go @@ -1,6 +1,7 @@ package handlers import ( + "fmt" "net/http" "strconv" @@ -8,6 +9,7 @@ import ( "github.com/ctwj/urldb/db/dto" "github.com/ctwj/urldb/db/entity" "github.com/ctwj/urldb/middleware" + "github.com/ctwj/urldb/utils" "github.com/gin-gonic/gin" ) @@ -20,18 +22,24 @@ func Login(c *gin.Context) { return } + clientIP, _ := c.Get("client_ip") + utils.Info("Login - 尝试登录 - 用户名: %s, IP: %s", req.Username, clientIP) + user, err := repoManager.UserRepository.FindByUsername(req.Username) if err != nil { + utils.Warn("Login - 用户不存在或密码错误 - 用户名: %s, IP: %s", req.Username, clientIP) ErrorResponse(c, "用户名或密码错误", http.StatusUnauthorized) return } if !user.IsActive { + utils.Warn("Login - 账户已被禁用 - 用户名: %s, IP: %s", req.Username, clientIP) ErrorResponse(c, "账户已被禁用", http.StatusUnauthorized) return } if !middleware.CheckPassword(req.Password, user.Password) { + utils.Warn("Login - 密码错误 - 用户名: %s, IP: %s", req.Username, clientIP) ErrorResponse(c, "用户名或密码错误", http.StatusUnauthorized) return } @@ -42,10 +50,13 @@ func Login(c *gin.Context) { // 生成JWT令牌 token, err := middleware.GenerateToken(user) if err != nil { + utils.Error("Login - 生成令牌失败 - 用户名: %s, IP: %s, Error: %v", req.Username, clientIP, err) ErrorResponse(c, "生成令牌失败", http.StatusInternalServerError) return } + utils.Info("Login - 登录成功 - 用户名: %s(ID:%d), IP: %s", req.Username, user.ID, clientIP) + response := dto.LoginResponse{ Token: token, User: converter.ToUserResponse(user), @@ -62,9 +73,13 @@ func Register(c *gin.Context) { return } + clientIP, _ := c.Get("client_ip") + utils.Info("Register - 尝试注册 - 用户名: %s, 邮箱: %s, IP: %s", req.Username, req.Email, clientIP) + // 检查用户名是否已存在 existingUser, _ := repoManager.UserRepository.FindByUsername(req.Username) if existingUser != nil { + utils.Warn("Register - 用户名已存在 - 用户名: %s, IP: %s", req.Username, clientIP) ErrorResponse(c, "用户名已存在", http.StatusBadRequest) return } @@ -72,6 +87,7 @@ func Register(c *gin.Context) { // 检查邮箱是否已存在 existingEmail, _ := repoManager.UserRepository.FindByEmail(req.Email) if existingEmail != nil { + utils.Warn("Register - 邮箱已存在 - 邮箱: %s, IP: %s", req.Email, clientIP) ErrorResponse(c, "邮箱已存在", http.StatusBadRequest) return } @@ -79,6 +95,7 @@ func Register(c *gin.Context) { // 哈希密码 hashedPassword, err := middleware.HashPassword(req.Password) if err != nil { + utils.Error("Register - 密码加密失败 - 用户名: %s, IP: %s, Error: %v", req.Username, clientIP, err) ErrorResponse(c, "密码加密失败", http.StatusInternalServerError) return } @@ -93,10 +110,13 @@ func Register(c *gin.Context) { err = repoManager.UserRepository.Create(user) if err != nil { + utils.Error("Register - 创建用户失败 - 用户名: %s, IP: %s, Error: %v", req.Username, clientIP, err) ErrorResponse(c, err.Error(), http.StatusInternalServerError) return } + utils.Info("Register - 注册成功 - 用户名: %s(ID:%d), 邮箱: %s, IP: %s", req.Username, user.ID, req.Email, clientIP) + SuccessResponse(c, gin.H{ "message": "注册成功", "user": converter.ToUserResponse(user), @@ -123,9 +143,14 @@ func CreateUser(c *gin.Context) { return } + adminUsername, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("CreateUser - 管理员创建用户 - 管理员: %s, 新用户名: %s, IP: %s", adminUsername, req.Username, clientIP) + // 检查用户名是否已存在 existingUser, _ := repoManager.UserRepository.FindByUsername(req.Username) if existingUser != nil { + utils.Warn("CreateUser - 用户名已存在 - 管理员: %s, 用户名: %s, IP: %s", adminUsername, req.Username, clientIP) ErrorResponse(c, "用户名已存在", http.StatusBadRequest) return } @@ -133,6 +158,7 @@ func CreateUser(c *gin.Context) { // 检查邮箱是否已存在 existingEmail, _ := repoManager.UserRepository.FindByEmail(req.Email) if existingEmail != nil { + utils.Warn("CreateUser - 邮箱已存在 - 管理员: %s, 邮箱: %s, IP: %s", adminUsername, req.Email, clientIP) ErrorResponse(c, "邮箱已存在", http.StatusBadRequest) return } @@ -140,6 +166,7 @@ func CreateUser(c *gin.Context) { // 哈希密码 hashedPassword, err := middleware.HashPassword(req.Password) if err != nil { + utils.Error("CreateUser - 密码加密失败 - 管理员: %s, 用户名: %s, IP: %s, Error: %v", adminUsername, req.Username, clientIP, err) ErrorResponse(c, "密码加密失败", http.StatusInternalServerError) return } @@ -154,10 +181,13 @@ func CreateUser(c *gin.Context) { err = repoManager.UserRepository.Create(user) if err != nil { + utils.Error("CreateUser - 创建用户失败 - 管理员: %s, 用户名: %s, IP: %s, Error: %v", adminUsername, req.Username, clientIP, err) ErrorResponse(c, err.Error(), http.StatusInternalServerError) return } + utils.Info("CreateUser - 用户创建成功 - 管理员: %s, 用户名: %s(ID:%d), 角色: %s, IP: %s", adminUsername, req.Username, user.ID, req.Role, clientIP) + SuccessResponse(c, gin.H{ "message": "用户创建成功", "user": converter.ToUserResponse(user), @@ -179,12 +209,21 @@ func UpdateUser(c *gin.Context) { return } + adminUsername, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("UpdateUser - 管理员更新用户 - 管理员: %s, 目标用户ID: %d, IP: %s", adminUsername, id, clientIP) + user, err := repoManager.UserRepository.FindByID(uint(id)) if err != nil { + utils.Warn("UpdateUser - 目标用户不存在 - 管理员: %s, 用户ID: %d, IP: %s", adminUsername, id, clientIP) ErrorResponse(c, "用户不存在", http.StatusNotFound) return } + // 记录变更前的信息 + oldInfo := fmt.Sprintf("用户名:%s,邮箱:%s,角色:%s,状态:%t", user.Username, user.Email, user.Role, user.IsActive) + utils.Debug("UpdateUser - 更新前用户信息 - 管理员: %s, 用户ID: %d, 信息: %s", adminUsername, id, oldInfo) + if req.Username != "" { user.Username = req.Username } @@ -198,10 +237,15 @@ func UpdateUser(c *gin.Context) { err = repoManager.UserRepository.Update(user) if err != nil { + utils.Error("UpdateUser - 更新用户失败 - 管理员: %s, 用户ID: %d, IP: %s, Error: %v", adminUsername, id, clientIP, err) ErrorResponse(c, err.Error(), http.StatusInternalServerError) return } + // 记录变更后信息 + newInfo := fmt.Sprintf("用户名:%s,邮箱:%s,角色:%s,状态:%t", user.Username, user.Email, user.Role, user.IsActive) + utils.Info("UpdateUser - 用户更新成功 - 管理员: %s, 用户ID: %d, 更新前: %s, 更新后: %s, IP: %s", adminUsername, id, oldInfo, newInfo, clientIP) + SuccessResponse(c, gin.H{"message": "用户更新成功"}) } @@ -220,8 +264,13 @@ func ChangePassword(c *gin.Context) { return } + adminUsername, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("ChangePassword - 管理员修改用户密码 - 管理员: %s, 目标用户ID: %d, IP: %s", adminUsername, id, clientIP) + user, err := repoManager.UserRepository.FindByID(uint(id)) if err != nil { + utils.Warn("ChangePassword - 目标用户不存在 - 管理员: %s, 用户ID: %d, IP: %s", adminUsername, id, clientIP) ErrorResponse(c, "用户不存在", http.StatusNotFound) return } @@ -229,6 +278,7 @@ func ChangePassword(c *gin.Context) { // 哈希新密码 hashedPassword, err := middleware.HashPassword(req.NewPassword) if err != nil { + utils.Error("ChangePassword - 密码加密失败 - 管理员: %s, 用户ID: %d, IP: %s, Error: %v", adminUsername, id, clientIP, err) ErrorResponse(c, "密码加密失败", http.StatusInternalServerError) return } @@ -236,10 +286,13 @@ func ChangePassword(c *gin.Context) { user.Password = hashedPassword err = repoManager.UserRepository.Update(user) if err != nil { + utils.Error("ChangePassword - 更新密码失败 - 管理员: %s, 用户ID: %d, IP: %s, Error: %v", adminUsername, id, clientIP, err) ErrorResponse(c, err.Error(), http.StatusInternalServerError) return } + utils.Info("ChangePassword - 密码修改成功 - 管理员: %s, 用户名: %s(ID:%d), IP: %s", adminUsername, user.Username, id, clientIP) + SuccessResponse(c, gin.H{"message": "密码修改成功"}) } @@ -252,12 +305,27 @@ func DeleteUser(c *gin.Context) { return } + adminUsername, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("DeleteUser - 管理员删除用户 - 管理员: %s, 目标用户ID: %d, IP: %s", adminUsername, id, clientIP) + + // 先获取用户信息用于日志记录 + user, err := repoManager.UserRepository.FindByID(uint(id)) + if err != nil { + utils.Warn("DeleteUser - 目标用户不存在 - 管理员: %s, 用户ID: %d, IP: %s", adminUsername, id, clientIP) + ErrorResponse(c, "用户不存在", http.StatusNotFound) + return + } + err = repoManager.UserRepository.Delete(uint(id)) if err != nil { + utils.Error("DeleteUser - 删除用户失败 - 管理员: %s, 用户ID: %d, IP: %s, Error: %v", adminUsername, id, clientIP, err) ErrorResponse(c, err.Error(), http.StatusInternalServerError) return } + utils.Info("DeleteUser - 用户删除成功 - 管理员: %s, 用户名: %s(ID:%d), IP: %s", adminUsername, user.Username, id, clientIP) + SuccessResponse(c, gin.H{"message": "用户删除成功"}) } @@ -269,12 +337,18 @@ func GetProfile(c *gin.Context) { return } + username, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + utils.Info("GetProfile - 用户获取个人资料 - 用户名: %s(ID:%d), IP: %s", username, userID, clientIP) + user, err := repoManager.UserRepository.FindByID(userID.(uint)) if err != nil { + utils.Warn("GetProfile - 用户不存在 - 用户名: %s(ID:%d), IP: %s", username, userID, clientIP) ErrorResponse(c, "用户不存在", http.StatusNotFound) return } response := converter.ToUserResponse(user) + utils.Debug("GetProfile - 成功获取个人资料 - 用户名: %s(ID:%d), IP: %s", username, userID, clientIP) SuccessResponse(c, response) } diff --git a/main.go b/main.go index 725e860..5165e98 100644 --- a/main.go +++ b/main.go @@ -41,7 +41,6 @@ func main() { if err := utils.InitLogger(nil); err != nil { log.Fatal("初始化日志系统失败:", err) } - defer utils.GetLogger().Close() // 加载环境变量 if err := godotenv.Load(); err != nil { diff --git a/middleware/auth.go b/middleware/auth.go index 4f4f43e..aa4c6d1 100644 --- a/middleware/auth.go +++ b/middleware/auth.go @@ -27,11 +27,14 @@ type Claims struct { func AuthMiddleware() gin.HandlerFunc { return func(c *gin.Context) { authHeader := c.GetHeader("Authorization") - // utils.Info("AuthMiddleware - 收到请求: %s %s", c.Request.Method, c.Request.URL.Path) - // utils.Info("AuthMiddleware - Authorization头: %s", authHeader) + clientIP := c.ClientIP() + userAgent := c.Request.UserAgent() + + utils.Debug("AuthMiddleware - 认证请求: %s %s, IP: %s, UserAgent: %s", + c.Request.Method, c.Request.URL.Path, clientIP, userAgent) if authHeader == "" { - utils.Error("AuthMiddleware - 未提供认证令牌") + utils.Warn("AuthMiddleware - 未提供认证令牌 - IP: %s, Path: %s", clientIP, c.Request.URL.Path) c.JSON(http.StatusUnauthorized, gin.H{"error": "未提供认证令牌"}) c.Abort() return @@ -39,29 +42,31 @@ func AuthMiddleware() gin.HandlerFunc { // 检查Bearer前缀 if !strings.HasPrefix(authHeader, "Bearer ") { - // utils.Error("AuthMiddleware - 无效的认证格式: %s", authHeader) + utils.Warn("AuthMiddleware - 无效的认证格式 - IP: %s, Header: %s", clientIP, authHeader) c.JSON(http.StatusUnauthorized, gin.H{"error": "无效的认证格式"}) c.Abort() return } tokenString := strings.TrimPrefix(authHeader, "Bearer ") - // utils.Info("AuthMiddleware - 解析令牌: %s", tokenString[:10]+"...") + utils.Debug("AuthMiddleware - 解析令牌: %s...", tokenString[:utils.Min(len(tokenString), 10)]) claims, err := parseToken(tokenString) if err != nil { - // utils.Error("AuthMiddleware - 令牌解析失败: %v", err) + utils.Warn("AuthMiddleware - 令牌解析失败 - IP: %s, Error: %v", clientIP, err) c.JSON(http.StatusUnauthorized, gin.H{"error": "无效的令牌"}) c.Abort() return } - // utils.Info("AuthMiddleware - 令牌验证成功，用户: %s, 角色: %s", claims.Username, claims.Role) + utils.Info("AuthMiddleware - 认证成功 - 用户: %s(ID:%d), 角色: %s, IP: %s", + claims.Username, claims.UserID, claims.Role, clientIP) // 将用户信息存储到上下文中 c.Set("user_id", claims.UserID) c.Set("username", claims.Username) c.Set("role", claims.Role) + c.Set("client_ip", clientIP) c.Next() } @@ -71,18 +76,23 @@ func AuthMiddleware() gin.HandlerFunc { func AdminMiddleware() gin.HandlerFunc { return func(c *gin.Context) { role, exists := c.Get("role") + username, _ := c.Get("username") + clientIP, _ := c.Get("client_ip") + if !exists { - // c.JSON(http.StatusUnauthorized, gin.H{"error": "未认证"}) + utils.Warn("AdminMiddleware - 未认证访问管理员接口 - IP: %s, Path: %s", clientIP, c.Request.URL.Path) c.Abort() return } if role != "admin" { - // c.JSON(http.StatusForbidden, gin.H{"error": "需要管理员权限"}) + utils.Warn("AdminMiddleware - 非管理员用户尝试访问管理员接口 - 用户: %s, 角色: %s, IP: %s, Path: %s", + username, role, clientIP, c.Request.URL.Path) c.Abort() return } + utils.Debug("AdminMiddleware - 管理员访问接口 - 用户: %s, IP: %s, Path: %s", username, clientIP, c.Request.URL.Path) c.Next() } } diff --git a/task/expansion_processor.go b/task/expansion_processor.go index 6e9142a..4697d69 100644 --- a/task/expansion_processor.go +++ b/task/expansion_processor.go @@ -53,25 +53,47 @@ type ExpansionOutput struct { // Process 处理扩容任务项 func (ep *ExpansionProcessor) Process(ctx context.Context, taskID uint, item *entity.TaskItem) error { - utils.Info("开始处理扩容任务项: %d", item.ID) + startTime := utils.GetCurrentTime() + utils.InfoWithFields(map[string]interface{}{ + "task_item_id": item.ID, + "task_id": taskID, + }, "开始处理扩容任务项: %d", item.ID) // 解析输入数据 + parseStart := utils.GetCurrentTime() var input ExpansionInput if err := json.Unmarshal([]byte(item.InputData), &input); err != nil { + parseDuration := time.Since(parseStart) + utils.ErrorWithFields(map[string]interface{}{ + "error": err.Error(), + "duration_ms": parseDuration.Milliseconds(), + }, "解析输入数据失败: %v，耗时: %v", err, parseDuration) return fmt.Errorf("解析输入数据失败: %v", err) } + parseDuration := time.Since(parseStart) + utils.DebugWithFields(map[string]interface{}{ + "duration_ms": parseDuration.Milliseconds(), + }, "解析输入数据完成，耗时: %v", parseDuration) // 验证输入数据 + validateStart := utils.GetCurrentTime() if err := ep.validateInput(&input); err != nil { + validateDuration := time.Since(validateStart) + utils.Error("输入数据验证失败: %v，耗时: %v", err, validateDuration) return fmt.Errorf("输入数据验证失败: %v", err) } + validateDuration := time.Since(validateStart) + utils.Debug("输入数据验证完成，耗时: %v", validateDuration) // 检查账号是否已经扩容过 + checkExpansionStart := utils.GetCurrentTime() exists, err := ep.checkExpansionExists(input.PanAccountID) + checkExpansionDuration := time.Since(checkExpansionStart) if err != nil { - utils.Error("检查扩容记录失败: %v", err) + utils.Error("检查扩容记录失败: %v，耗时: %v", err, checkExpansionDuration) return fmt.Errorf("检查扩容记录失败: %v", err) } + utils.Debug("检查扩容记录完成，耗时: %v", checkExpansionDuration) if exists { output := ExpansionOutput{ @@ -89,7 +111,9 @@ func (ep *ExpansionProcessor) Process(ctx context.Context, taskID uint, item *en } // 检查账号类型（只支持quark账号） + checkAccountTypeStart := utils.GetCurrentTime() if err := ep.checkAccountType(input.PanAccountID); err != nil { + checkAccountTypeDuration := time.Since(checkAccountTypeStart) output := ExpansionOutput{ Success: false, Message: "账号类型不支持扩容", @@ -100,12 +124,16 @@ func (ep *ExpansionProcessor) Process(ctx context.Context, taskID uint, item *en outputJSON, _ := json.Marshal(output) item.OutputData = string(outputJSON) - utils.Error("账号类型不支持扩容: %v", err) + utils.Error("账号类型不支持扩容: %v，耗时: %v", err, checkAccountTypeDuration) return err } + checkAccountTypeDuration := time.Since(checkAccountTypeStart) + utils.Debug("检查账号类型完成，耗时: %v", checkAccountTypeDuration) // 执行扩容操作（传入数据源） + expansionStart := utils.GetCurrentTime() transferred, err := ep.performExpansion(ctx, input.PanAccountID, input.DataSource) + expansionDuration := time.Since(expansionStart) if err != nil { output := ExpansionOutput{ Success: false, @@ -117,9 +145,10 @@ func (ep *ExpansionProcessor) Process(ctx context.Context, taskID uint, item *en outputJSON, _ := json.Marshal(output) item.OutputData = string(outputJSON) - utils.Error("扩容任务项处理失败: %d, 错误: %v", item.ID, err) + utils.Error("扩容任务项处理失败: %d, 错误: %v，总耗时: %v", item.ID, err, expansionDuration) return fmt.Errorf("扩容失败: %v", err) } + utils.Debug("扩容操作完成，耗时: %v", expansionDuration) // 扩容成功 output := ExpansionOutput{ @@ -132,27 +161,44 @@ func (ep *ExpansionProcessor) Process(ctx context.Context, taskID uint, item *en outputJSON, _ := json.Marshal(output) item.OutputData = string(outputJSON) - utils.Info("扩容任务项处理完成: %d, 账号ID: %d", item.ID, input.PanAccountID) + elapsedTime := time.Since(startTime) + utils.InfoWithFields(map[string]interface{}{ + "task_item_id": item.ID, + "account_id": input.PanAccountID, + "duration_ms": elapsedTime.Milliseconds(), + }, "扩容任务项处理完成: %d, 账号ID: %d, 总耗时: %v", item.ID, input.PanAccountID, elapsedTime) return nil } // validateInput 验证输入数据 func (ep *ExpansionProcessor) validateInput(input *ExpansionInput) error { + startTime := utils.GetCurrentTime() + if input.PanAccountID == 0 { + utils.Error("账号ID验证失败，账号ID不能为空，耗时: %v", time.Since(startTime)) return fmt.Errorf("账号ID不能为空") } + + utils.Debug("输入数据验证完成，耗时: %v", time.Since(startTime)) return nil } // checkExpansionExists 检查账号是否已经扩容过 func (ep *ExpansionProcessor) checkExpansionExists(panAccountID uint) (bool, error) { + startTime := utils.GetCurrentTime() + // 查询所有expansion类型的任务 + tasksStart := utils.GetCurrentTime() tasks, _, err := ep.repoMgr.TaskRepository.GetList(1, 1000, "expansion", "completed") + tasksDuration := time.Since(tasksStart) if err != nil { + utils.Error("获取扩容任务列表失败: %v，耗时: %v", err, tasksDuration) return false, fmt.Errorf("获取扩容任务列表失败: %v", err) } + utils.Debug("获取扩容任务列表完成，找到 %d 个任务，耗时: %v", len(tasks), tasksDuration) // 检查每个任务的配置中是否包含该账号ID + checkStart := utils.GetCurrentTime() for _, task := range tasks { if task.Config != "" { var taskConfig map[string]interface{} @@ -162,6 +208,8 @@ func (ep *ExpansionProcessor) checkExpansionExists(panAccountID uint) (bool, err // 找到了该账号的扩容任务，检查任务状态 if task.Status == "completed" { // 如果任务已完成，说明已经扩容过 + checkDuration := time.Since(checkStart) + utils.Debug("检查扩容记录完成，账号已扩容，耗时: %v", checkDuration) return true, nil } } @@ -169,40 +217,63 @@ func (ep *ExpansionProcessor) checkExpansionExists(panAccountID uint) (bool, err } } } + checkDuration := time.Since(checkStart) + utils.Debug("检查扩容记录完成，账号未扩容，耗时: %v", checkDuration) + totalDuration := time.Since(startTime) + utils.Debug("检查扩容记录完成，账号未扩容，总耗时: %v", totalDuration) return false, nil } // checkAccountType 检查账号类型（只支持quark账号） func (ep *ExpansionProcessor) checkAccountType(panAccountID uint) error { + startTime := utils.GetCurrentTime() + // 获取账号信息 + accountStart := utils.GetCurrentTime() cks, err := ep.repoMgr.CksRepository.FindByID(panAccountID) + accountDuration := time.Since(accountStart) if err != nil { + utils.Error("获取账号信息失败: %v，耗时: %v", err, accountDuration) return fmt.Errorf("获取账号信息失败: %v", err) } + utils.Debug("获取账号信息完成，耗时: %v", accountDuration) // 检查是否为quark账号 + serviceCheckStart := utils.GetCurrentTime() if cks.ServiceType != "quark" { + serviceCheckDuration := time.Since(serviceCheckStart) + utils.Error("账号类型检查失败，当前账号类型: %s，耗时: %v", cks.ServiceType, serviceCheckDuration) return fmt.Errorf("只支持quark账号扩容，当前账号类型: %s", cks.ServiceType) } + serviceCheckDuration := time.Since(serviceCheckStart) + utils.Debug("账号类型检查完成，为quark账号，耗时: %v", serviceCheckDuration) + totalDuration := time.Since(startTime) + utils.Debug("账号类型检查完成，总耗时: %v", totalDuration) return nil } // performExpansion 执行扩容操作 func (ep *ExpansionProcessor) performExpansion(ctx context.Context, panAccountID uint, dataSource map[string]interface{}) ([]TransferredResource, error) { rand.Seed(time.Now().UnixNano()) + startTime := utils.GetCurrentTime() utils.Info("执行扩容操作，账号ID: %d, 数据源: %v", panAccountID, dataSource) transferred := []TransferredResource{} // 获取账号信息 + accountStart := utils.GetCurrentTime() account, err := ep.repoMgr.CksRepository.FindByID(panAccountID) + accountDuration := time.Since(accountStart) if err != nil { + utils.Error("获取账号信息失败: %v，耗时: %v", err, accountDuration) return nil, fmt.Errorf("获取账号信息失败: %v", err) } + utils.Debug("获取账号信息完成，耗时: %v", accountDuration) // 创建网盘服务工厂 + serviceStart := utils.GetCurrentTime() factory := pan.NewPanFactory() service, err := factory.CreatePanServiceByType(pan.Quark, &pan.PanConfig{ URL: "", @@ -210,10 +281,13 @@ func (ep *ExpansionProcessor) performExpansion(ctx context.Context, panAccountID IsType: 0, Cookie: account.Ck, }) + serviceDuration := time.Since(serviceStart) if err != nil { + utils.Error("创建网盘服务失败: %v，耗时: %v", err, serviceDuration) return nil, fmt.Errorf("创建网盘服务失败: %v", err) } service.SetCKSRepository(ep.repoMgr.CksRepository, *account) + utils.Debug("创建网盘服务完成，耗时: %v", serviceDuration) // 定义扩容分类列表（按优先级排序） categories := []string{ @@ -246,11 +320,14 @@ func (ep *ExpansionProcessor) performExpansion(ctx context.Context, panAccountID utils.Info("开始处理分类: %s", category) // 获取该分类的资源 + resourcesStart := utils.GetCurrentTime() resources, err := ep.getHotResources(category) + resourcesDuration := time.Since(resourcesStart) if err != nil { - utils.Error("获取分类 %s 的资源失败: %v", category, err) + utils.Error("获取分类 %s 的资源失败: %v，耗时: %v", category, err, resourcesDuration) continue } + utils.Debug("获取分类 %s 的资源完成，耗时: %v", category, resourcesDuration) if len(resources) == 0 { utils.Info("分类 %s 没有可用资源，跳过", category) @@ -269,11 +346,14 @@ func (ep *ExpansionProcessor) performExpansion(ctx context.Context, panAccountID } // 检查是否还有存储空间 + storageCheckStart := utils.GetCurrentTime() hasSpace, err := ep.checkStorageSpace(service, &account.Ck) + storageCheckDuration := time.Since(storageCheckStart) if err != nil { - utils.Error("检查存储空间失败: %v", err) + utils.Error("检查存储空间失败: %v，耗时: %v", err, storageCheckDuration) return transferred, fmt.Errorf("检查存储空间失败: %v", err) } + utils.Debug("检查存储空间完成，耗时: %v", storageCheckDuration) if !hasSpace { utils.Info("存储空间不足，停止扩容，但保存已转存的资源") @@ -282,24 +362,30 @@ func (ep *ExpansionProcessor) performExpansion(ctx context.Context, panAccountID } // 获取资源 , dataSourceType, thirdPartyURL + resourceGetStart := utils.GetCurrentTime() resource, err := ep.getResourcesByHot(resource, dataSourceType, thirdPartyURL, *account, service) + resourceGetDuration := time.Since(resourceGetStart) if resource == nil || err != nil { if resource != nil { - utils.Error("获取资源失败: %s, 错误: %v", resource.Title, err) + utils.Error("获取资源失败: %s, 错误: %v，耗时: %v", resource.Title, err, resourceGetDuration) } else { - utils.Error("获取资源失败, 错误: %v", err) + utils.Error("获取资源失败, 错误: %v，耗时: %v", err, resourceGetDuration) } totalFailed++ continue } + utils.Debug("获取资源完成，耗时: %v", resourceGetDuration) // 执行转存 + transferStart := utils.GetCurrentTime() saveURL, err := ep.transferResource(ctx, service, resource, *account) + transferDuration := time.Since(transferStart) if err != nil { - utils.Error("转存资源失败: %s, 错误: %v", resource.Title, err) + utils.Error("转存资源失败: %s, 错误: %v，耗时: %v", resource.Title, err, transferDuration) totalFailed++ continue } + utils.Debug("转存资源完成，耗时: %v", transferDuration) // 随机休眠1-3秒，避免请求过于频繁 sleepDuration := time.Duration(rand.Intn(3)+1) * time.Second @@ -324,7 +410,8 @@ func (ep *ExpansionProcessor) performExpansion(ctx context.Context, panAccountID utils.Info("分类 %s 处理完成，转存 %d 个资源", category, transferredCount) } - utils.Info("扩容完成，总共转存: %d 个资源，失败: %d 个资源", totalTransferred, totalFailed) + elapsedTime := time.Since(startTime) + utils.Info("扩容完成，总共转存: %d 个资源，失败: %d 个资源，总耗时: %v", totalTransferred, totalFailed, elapsedTime) return transferred, nil } @@ -335,27 +422,45 @@ func (ep *ExpansionProcessor) getResourcesByHot( entity entity.Cks, service pan.PanService, ) (*entity.Resource, error) { + startTime := utils.GetCurrentTime() + if dataSourceType == "third-party" && thirdPartyURL != "" { // 从第三方API获取资源 - return ep.getResourcesFromThirdPartyAPI(resource, thirdPartyURL) + thirdPartyStart := utils.GetCurrentTime() + result, err := ep.getResourcesFromThirdPartyAPI(resource, thirdPartyURL) + thirdPartyDuration := time.Since(thirdPartyStart) + utils.Debug("从第三方API获取资源完成，耗时: %v", thirdPartyDuration) + return result, err } // 从内部数据库获取资源 - return ep.getResourcesFromInternalDB(resource, entity, service) + internalStart := utils.GetCurrentTime() + result, err := ep.getResourcesFromInternalDB(resource, entity, service) + internalDuration := time.Since(internalStart) + utils.Debug("从内部数据库获取资源完成，耗时: %v", internalDuration) + + totalDuration := time.Since(startTime) + utils.Debug("获取资源完成: %s，总耗时: %v", resource.Title, totalDuration) + return result, err } // getResourcesFromInternalDB 根据 HotDrama 的title 获取数据库中资源，并且资源的类型和 account 的资源类型一致 func (ep *ExpansionProcessor) getResourcesFromInternalDB(HotDrama *entity.HotDrama, account entity.Cks, service pan.PanService) (*entity.Resource, error) { + startTime := utils.GetCurrentTime() + // 修改配置 isType = 1 只检测，不转存 + configStart := utils.GetCurrentTime() service.UpdateConfig(&pan.PanConfig{ URL: "", ExpiredType: 0, IsType: 1, Cookie: account.Ck, }) + utils.Debug("更新服务配置完成，耗时: %v", time.Since(configStart)) panID := account.PanID // 1. 搜索标题 + searchStart := utils.GetCurrentTime() params := map[string]interface{}{ "search": HotDrama.Title, "pan_id": panID, @@ -364,11 +469,15 @@ func (ep *ExpansionProcessor) getResourcesFromInternalDB(HotDrama *entity.HotDra "page_size": 10, } resources, _, err := ep.repoMgr.ResourceRepository.SearchWithFilters(params) + searchDuration := time.Since(searchStart) if err != nil { + utils.Error("搜索资源失败: %v，耗时: %v", err, searchDuration) return nil, fmt.Errorf("搜索资源失败: %v", err) } + utils.Debug("搜索资源完成，找到 %d 个资源，耗时: %v", len(resources), searchDuration) // 检查结果是否有效，通过服务验证 + validateStart := utils.GetCurrentTime() for _, res := range resources { if res.IsValid && res.URL != "" { // 使用服务验证资源是否可转存 @@ -376,38 +485,59 @@ func (ep *ExpansionProcessor) getResourcesFromInternalDB(HotDrama *entity.HotDra if shareID != "" { result, err := service.Transfer(shareID) if err == nil && result != nil && result.Success { + validateDuration := time.Since(validateStart) + utils.Debug("验证资源成功: %s，耗时: %v", res.Title, validateDuration) return &res, nil } } } } + validateDuration := time.Since(validateStart) + utils.Debug("验证资源完成，未找到有效资源，耗时: %v", validateDuration) + totalDuration := time.Since(startTime) + utils.Debug("从内部数据库获取资源完成: %s，总耗时: %v", HotDrama.Title, totalDuration) // 3. 没有有效资源，返回错误信息 return nil, fmt.Errorf("未找到有效的资源") } // getResourcesFromInternalDB 从内部数据库获取资源 func (ep *ExpansionProcessor) getHotResources(category string) ([]*entity.HotDrama, error) { + startTime := utils.GetCurrentTime() + // 获取该分类下sub_type为"排行"的资源 + rankedStart := utils.GetCurrentTime() dramas, _, err := ep.repoMgr.HotDramaRepository.FindByCategoryAndSubType(category, "排行", 1, 20) + rankedDuration := time.Since(rankedStart) if err != nil { + utils.Error("获取分类 %s 的排行资源失败: %v，耗时: %v", category, err, rankedDuration) return nil, fmt.Errorf("获取分类 %s 的资源失败: %v", category, err) } + utils.Debug("获取分类 %s 的排行资源完成，找到 %d 个资源，耗时: %v", category, len(dramas), rankedDuration) // 如果没有找到"排行"类型的资源，尝试获取该分类下的所有资源 if len(dramas) == 0 { + allStart := utils.GetCurrentTime() dramas, _, err = ep.repoMgr.HotDramaRepository.FindByCategory(category, 1, 20) + allDuration := time.Since(allStart) if err != nil { + utils.Error("获取分类 %s 的所有资源失败: %v，耗时: %v", category, err, allDuration) return nil, fmt.Errorf("获取分类 %s 的资源失败: %v", category, err) } + utils.Debug("获取分类 %s 的所有资源完成，找到 %d 个资源，耗时: %v", category, len(dramas), allDuration) } // 转换为指针数组 + convertStart := utils.GetCurrentTime() result := make([]*entity.HotDrama, len(dramas)) for i := range dramas { result[i] = &dramas[i] } + convertDuration := time.Since(convertStart) + utils.Debug("转换资源数组完成，耗时: %v", convertDuration) + totalDuration := time.Since(startTime) + utils.Debug("获取热门资源完成: 分类 %s，总数 %d，总耗时: %v", category, len(result), totalDuration) return result, nil } @@ -423,50 +553,69 @@ func (ep *ExpansionProcessor) getResourcesFromThirdPartyAPI(resource *entity.Hot // checkStorageSpace 检查存储空间是否足够 func (ep *ExpansionProcessor) checkStorageSpace(service pan.PanService, ck *string) (bool, error) { + startTime := utils.GetCurrentTime() + + userInfoStart := utils.GetCurrentTime() userInfo, err := service.GetUserInfo(ck) + userInfoDuration := time.Since(userInfoStart) if err != nil { - utils.Error("获取用户信息失败: %v", err) + utils.Error("获取用户信息失败: %v，耗时: %v", err, userInfoDuration) // 如果无法获取用户信息，假设还有空间继续 return true, nil } + utils.Debug("获取用户信息完成，耗时: %v", userInfoDuration) // 检查是否还有足够的空间（保留至少10GB空间） const reservedSpaceGB = 100 reservedSpaceBytes := int64(reservedSpaceGB * 1024 * 1024 * 1024) if userInfo.TotalSpace-userInfo.UsedSpace <= reservedSpaceBytes { - utils.Info("存储空间不足，已使用: %d bytes，总容量: %d bytes", - userInfo.UsedSpace, userInfo.TotalSpace) + utils.Info("存储空间不足，已使用: %d bytes，总容量: %d bytes，检查耗时: %v", + userInfo.UsedSpace, userInfo.TotalSpace, time.Since(startTime)) return false, nil } + totalDuration := time.Since(startTime) + utils.Debug("存储空间检查完成，有足够空间，耗时: %v", totalDuration) return true, nil } // transferResource 执行单个资源的转存 func (ep *ExpansionProcessor) transferResource(ctx context.Context, service pan.PanService, res *entity.Resource, account entity.Cks) (string, error) { + startTime := utils.GetCurrentTime() + // 修改配置 isType = 0 转存 + configStart := utils.GetCurrentTime() service.UpdateConfig(&pan.PanConfig{ URL: "", ExpiredType: 0, IsType: 0, Cookie: account.Ck, }) + utils.Debug("更新服务配置完成，耗时: %v", time.Since(configStart)) // 如果没有URL，跳过转存 if res.URL == "" { + utils.Error("资源 %s 没有有效的URL", res.URL) return "", fmt.Errorf("资源 %s 没有有效的URL", res.URL) } // 提取分享ID + extractStart := utils.GetCurrentTime() shareID, _ := pan.ExtractShareId(res.URL) + extractDuration := time.Since(extractStart) if shareID == "" { + utils.Error("无法从URL %s 提取分享ID，耗时: %v", res.URL, extractDuration) return "", fmt.Errorf("无法从URL %s 提取分享ID", res.URL) } + utils.Debug("提取分享ID完成: %s，耗时: %v", shareID, extractDuration) // 执行转存 + transferStart := utils.GetCurrentTime() result, err := service.Transfer(shareID) + transferDuration := time.Since(transferStart) if err != nil { + utils.Error("转存失败: %v，耗时: %v", err, transferDuration) return "", fmt.Errorf("转存失败: %v", err) } @@ -475,10 +624,12 @@ func (ep *ExpansionProcessor) transferResource(ctx context.Context, service pan. if result != nil { errorMsg = result.Message } + utils.Error("转存结果失败: %s，耗时: %v", errorMsg, time.Since(transferStart)) return "", fmt.Errorf("转存失败: %s", errorMsg) } // 提取转存链接 + extractURLStart := utils.GetCurrentTime() var saveURL string if result.Data != nil { if data, ok := result.Data.(map[string]interface{}); ok { @@ -490,11 +641,14 @@ func (ep *ExpansionProcessor) transferResource(ctx context.Context, service pan. if saveURL == "" { saveURL = result.ShareURL } - if saveURL == "" { + extractURLDuration := time.Since(extractURLStart) + utils.Error("转存成功但未获取到分享链接，耗时: %v", extractURLDuration) return "", fmt.Errorf("转存成功但未获取到分享链接") } + totalDuration := time.Since(startTime) + utils.Debug("转存资源完成: %s -> %s，总耗时: %v", res.Title, saveURL, totalDuration) return saveURL, nil } diff --git a/task/task_processor.go b/task/task_processor.go index c3a9437..8d8cfa3 100644 --- a/task/task_processor.go +++ b/task/task_processor.go @@ -5,6 +5,7 @@ import ( "encoding/json" "fmt" "sync" + "time" "github.com/ctwj/urldb/db/entity" "github.com/ctwj/urldb/db/repo" @@ -90,7 +91,9 @@ func (tm *TaskManager) StartTask(taskID uint) error { // 启动后台任务 go tm.processTask(ctx, task, processor) - utils.Info("StartTask: 任务 %d 启动成功", taskID) + utils.InfoWithFields(map[string]interface{}{ + "task_id": taskID, + }, "StartTask: 任务 %d 启动成功", taskID) return nil } @@ -185,14 +188,19 @@ func (tm *TaskManager) StopTask(taskID uint) error { // processTask 处理任务 func (tm *TaskManager) processTask(ctx context.Context, task *entity.Task, processor TaskProcessor) { + startTime := utils.GetCurrentTime() defer func() { tm.mu.Lock() delete(tm.running, task.ID) tm.mu.Unlock() - utils.Debug("processTask: 任务 %d 处理完成，清理资源", task.ID) + elapsedTime := time.Since(startTime) + utils.Info("processTask: 任务 %d 处理完成，耗时: %v，清理资源", task.ID, elapsedTime) }() - utils.Debug("processTask: 开始处理任务: %d, 类型: %s", task.ID, task.Type) + utils.InfoWithFields(map[string]interface{}{ + "task_id": task.ID, + "task_type": task.Type, + }, "processTask: 开始处理任务: %d, 类型: %s", task.ID, task.Type) // 更新任务状态为运行中 err := tm.repoMgr.TaskRepository.UpdateStatus(task.ID, "running") @@ -208,7 +216,9 @@ func (tm *TaskManager) processTask(ctx context.Context, task *entity.Task, proce } // 获取任务项统计信息，用于计算正确的进度 + statsStart := utils.GetCurrentTime() stats, err := tm.repoMgr.TaskItemRepository.GetStatsByTaskID(task.ID) + statsDuration := time.Since(statsStart) if err != nil { utils.Error("获取任务项统计失败: %v", err) stats = map[string]int{ @@ -218,14 +228,20 @@ func (tm *TaskManager) processTask(ctx context.Context, task *entity.Task, proce "completed": 0, "failed": 0, } + } else { + utils.Debug("获取任务项统计完成，耗时: %v", statsDuration) } // 获取待处理的任务项 + itemsStart := utils.GetCurrentTime() items, err := tm.repoMgr.TaskItemRepository.GetByTaskIDAndStatus(task.ID, "pending") + itemsDuration := time.Since(itemsStart) if err != nil { utils.Error("获取任务项失败: %v", err) tm.markTaskFailed(task.ID, fmt.Sprintf("获取任务项失败: %v", err)) return + } else { + utils.Debug("获取任务项完成，数量: %d，耗时: %v", len(items), itemsDuration) } // 计算总任务项数和已完成的项数 @@ -236,10 +252,14 @@ func (tm *TaskManager) processTask(ctx context.Context, task *entity.Task, proce // 如果当前批次有处理中的任务项，重置它们为pending状态（服务器重启恢复） if processingItems > 0 { - utils.Debug("任务 %d 发现 %d 个处理中的任务项，重置为pending状态", task.ID, processingItems) + utils.Info("任务 %d 发现 %d 个处理中的任务项，重置为pending状态", task.ID, processingItems) + resetStart := utils.GetCurrentTime() err = tm.repoMgr.TaskItemRepository.ResetProcessingItems(task.ID) + resetDuration := time.Since(resetStart) if err != nil { utils.Error("重置处理中任务项失败: %v", err) + } else { + utils.Debug("重置处理中任务项完成，耗时: %v", resetDuration) } // 重新获取待处理的任务项 items, err = tm.repoMgr.TaskItemRepository.GetByTaskIDAndStatus(task.ID, "pending") @@ -258,21 +278,35 @@ func (tm *TaskManager) processTask(ctx context.Context, task *entity.Task, proce utils.Debug("任务 %d 统计信息: 总计=%d, 已完成=%d, 已失败=%d, 待处理=%d", task.ID, totalItems, completedItems, failedItems, currentBatchItems) - for _, item := range items { + // 记录处理开始时间 + batchStartTime := utils.GetCurrentTime() + + for i, item := range items { select { case <-ctx.Done(): utils.Debug("任务 %d 被取消", task.ID) return default: + // 记录单个任务项处理开始时间 + itemStartTime := utils.GetCurrentTime() + // 处理单个任务项 err := tm.processTaskItem(ctx, task.ID, item, processor) processedItems++ + // 记录单个任务项处理耗时 + itemDuration := time.Since(itemStartTime) + if err != nil { failedItems++ - utils.Error("处理任务项 %d 失败: %v", item.ID, err) + utils.ErrorWithFields(map[string]interface{}{ + "task_item_id": item.ID, + "error": err.Error(), + "duration_ms": itemDuration.Milliseconds(), + }, "处理任务项 %d 失败: %v，耗时: %v", item.ID, err, itemDuration) } else { successItems++ + utils.Info("处理任务项 %d 成功，耗时: %v", item.ID, itemDuration) } // 更新任务进度（基于总任务项数） @@ -280,9 +314,21 @@ func (tm *TaskManager) processTask(ctx context.Context, task *entity.Task, proce progress := float64(processedItems) / float64(totalItems) * 100 tm.updateTaskProgress(task.ID, progress, processedItems, successItems, failedItems) } + + // 每处理10个任务项记录一次批处理进度 + if (i+1)%10 == 0 || i == len(items)-1 { + batchDuration := time.Since(batchStartTime) + utils.Info("任务 %d 批处理进度: 已处理 %d/%d 项，成功 %d 项，失败 %d 项，当前批处理耗时: %v", + task.ID, processedItems, totalItems, successItems, failedItems, batchDuration) + } } } + // 记录整个批处理耗时 + batchDuration := time.Since(batchStartTime) + utils.Info("任务 %d 批处理完成: 总计 %d 项，成功 %d 项，失败 %d 项，总耗时: %v", + task.ID, len(items), successItems, failedItems, batchDuration) + // 任务完成 status := "completed" message := fmt.Sprintf("任务完成，共处理 %d 项，成功 %d 项，失败 %d 项", processedItems, successItems, failedItems) @@ -308,25 +354,41 @@ func (tm *TaskManager) processTask(ctx context.Context, task *entity.Task, proce } } - utils.Info("任务 %d 处理完成: %s", task.ID, message) + utils.InfoWithFields(map[string]interface{}{ + "task_id": task.ID, + "message": message, + }, "任务 %d 处理完成: %s", task.ID, message) } // processTaskItem 处理单个任务项 func (tm *TaskManager) processTaskItem(ctx context.Context, taskID uint, item *entity.TaskItem, processor TaskProcessor) error { + itemStartTime := utils.GetCurrentTime() + utils.Debug("开始处理任务项: %d (任务ID: %d)", item.ID, taskID) + // 更新任务项状态为处理中 + updateStart := utils.GetCurrentTime() err := tm.repoMgr.TaskItemRepository.UpdateStatus(item.ID, "processing") + updateDuration := time.Since(updateStart) if err != nil { + utils.Error("更新任务项状态失败: %v，耗时: %v", err, updateDuration) return fmt.Errorf("更新任务项状态失败: %v", err) + } else { + utils.Debug("更新任务项状态为处理中完成，耗时: %v", updateDuration) } // 处理任务项 + processStart := utils.GetCurrentTime() err = processor.Process(ctx, taskID, item) + processDuration := time.Since(processStart) if err != nil { // 处理失败 + utils.Error("处理任务项 %d 失败: %v，处理耗时: %v", item.ID, err, processDuration) + outputData := map[string]interface{}{ "error": err.Error(), "time": utils.GetCurrentTime(), + "duration_ms": processDuration.Milliseconds(), } outputJSON, _ := json.Marshal(outputData) @@ -338,25 +400,49 @@ func (tm *TaskManager) processTaskItem(ctx context.Context, taskID uint, item *e } // 处理成功 + utils.Info("处理任务项 %d 成功，处理耗时: %v", item.ID, processDuration) + // 如果处理器已经设置了 output_data（比如 ExpansionProcessor），则不覆盖 var outputJSON string if item.OutputData == "" { outputData := map[string]interface{}{ "success": true, "time": utils.GetCurrentTime(), + "duration_ms": processDuration.Milliseconds(), } outputBytes, _ := json.Marshal(outputData) outputJSON = string(outputBytes) } else { - // 使用处理器设置的 output_data - outputJSON = item.OutputData + // 使用处理器设置的 output_data，并添加处理时间信息 + var existingOutput map[string]interface{} + if json.Unmarshal([]byte(item.OutputData), &existingOutput) == nil { + existingOutput["duration_ms"] = processDuration.Milliseconds() + outputBytes, _ := json.Marshal(existingOutput) + outputJSON = string(outputBytes) + } else { + // 如果无法解析现有输出，保留原样并添加时间信息 + outputData := map[string]interface{}{ + "original_output": item.OutputData, + "success": true, + "time": utils.GetCurrentTime(), + "duration_ms": processDuration.Milliseconds(), + } + outputBytes, _ := json.Marshal(outputData) + outputJSON = string(outputBytes) + } } + updateSuccessStart := utils.GetCurrentTime() err = tm.repoMgr.TaskItemRepository.UpdateStatusAndOutput(item.ID, "completed", outputJSON) + updateSuccessDuration := time.Since(updateSuccessStart) if err != nil { - utils.Error("更新成功任务项状态失败: %v", err) + utils.Error("更新成功任务项状态失败: %v，耗时: %v", err, updateSuccessDuration) + } else { + utils.Debug("更新成功任务项状态完成，耗时: %v", updateSuccessDuration) } + itemDuration := time.Since(itemStartTime) + utils.Debug("任务项 %d 处理完成，总耗时: %v", item.ID, itemDuration) return nil } diff --git a/task/transfer_processor.go b/task/transfer_processor.go index 70a8445..525e63c 100644 --- a/task/transfer_processor.go +++ b/task/transfer_processor.go @@ -51,20 +51,42 @@ type TransferOutput struct { // Process 处理转存任务项 func (tp *TransferProcessor) Process(ctx context.Context, taskID uint, item *entity.TaskItem) error { - utils.Info("开始处理转存任务项: %d", item.ID) + startTime := utils.GetCurrentTime() + utils.InfoWithFields(map[string]interface{}{ + "task_item_id": item.ID, + "task_id": taskID, + }, "开始处理转存任务项: %d", item.ID) // 解析输入数据 + parseStart := utils.GetCurrentTime() var input TransferInput if err := json.Unmarshal([]byte(item.InputData), &input); err != nil { + parseDuration := time.Since(parseStart) + utils.ErrorWithFields(map[string]interface{}{ + "error": err.Error(), + "duration_ms": parseDuration.Milliseconds(), + }, "解析输入数据失败: %v，耗时: %v", err, parseDuration) return fmt.Errorf("解析输入数据失败: %v", err) } + parseDuration := time.Since(parseStart) + utils.DebugWithFields(map[string]interface{}{ + "duration_ms": parseDuration.Milliseconds(), + }, "解析输入数据完成，耗时: %v", parseDuration) // 验证输入数据 + validateStart := utils.GetCurrentTime() if err := tp.validateInput(&input); err != nil { + validateDuration := time.Since(validateStart) + utils.Error("输入数据验证失败: %v，耗时: %v", err, validateDuration) return fmt.Errorf("输入数据验证失败: %v", err) } + validateDuration := time.Since(validateStart) + utils.DebugWithFields(map[string]interface{}{ + "duration_ms": validateDuration.Milliseconds(), + }, "输入数据验证完成，耗时: %v", validateDuration) // 获取任务配置中的账号信息 + configStart := utils.GetCurrentTime() var selectedAccounts []uint task, err := tp.repoMgr.TaskRepository.GetByID(taskID) if err == nil && task.Config != "" { @@ -79,15 +101,21 @@ func (tp *TransferProcessor) Process(ctx context.Context, taskID uint, item *ent } } } + configDuration := time.Since(configStart) + utils.Debug("获取任务配置完成，耗时: %v", configDuration) if len(selectedAccounts) == 0 { utils.Error("失败: %v", "没有指定转存账号") } // 检查资源是否已存在 + checkStart := utils.GetCurrentTime() exists, existingResource, err := tp.checkResourceExists(input.URL) + checkDuration := time.Since(checkStart) if err != nil { - utils.Error("检查资源是否存在失败: %v", err) + utils.Error("检查资源是否存在失败: %v，耗时: %v", err, checkDuration) + } else { + utils.Debug("检查资源是否存在完成，耗时: %v", checkDuration) } if exists { @@ -107,19 +135,26 @@ func (tp *TransferProcessor) Process(ctx context.Context, taskID uint, item *ent outputJSON, _ := json.Marshal(output) item.OutputData = string(outputJSON) - utils.Info("资源已存在且有转存链接，跳过转存: %s", input.Title) + elapsedTime := time.Since(startTime) + utils.Info("资源已存在且有转存链接，跳过转存: %s，总耗时: %v", input.Title, elapsedTime) return nil } } // 查询出 账号列表 + cksStart := utils.GetCurrentTime() cks, err := tp.repoMgr.CksRepository.FindByIds(selectedAccounts) + cksDuration := time.Since(cksStart) if err != nil { - utils.Error("读取账号失败: %v", err) + utils.Error("读取账号失败: %v，耗时: %v", err, cksDuration) + } else { + utils.Debug("读取账号完成，账号数量: %d，耗时: %v", len(cks), cksDuration) } // 执行转存操作 + transferStart := utils.GetCurrentTime() resourceID, saveURL, err := tp.performTransfer(ctx, &input, cks) + transferDuration := time.Since(transferStart) if err != nil { // 转存失败，更新输出数据 output := TransferOutput{ @@ -131,7 +166,13 @@ func (tp *TransferProcessor) Process(ctx context.Context, taskID uint, item *ent outputJSON, _ := json.Marshal(output) item.OutputData = string(outputJSON) - utils.Error("转存任务项处理失败: %d, 错误: %v", item.ID, err) + elapsedTime := time.Since(startTime) + utils.ErrorWithFields(map[string]interface{}{ + "task_item_id": item.ID, + "error": err.Error(), + "duration_ms": transferDuration.Milliseconds(), + "total_ms": elapsedTime.Milliseconds(), + }, "转存任务项处理失败: %d, 错误: %v，转存耗时: %v，总耗时: %v", item.ID, err, transferDuration, elapsedTime) return fmt.Errorf("转存失败: %v", err) } @@ -146,7 +187,8 @@ func (tp *TransferProcessor) Process(ctx context.Context, taskID uint, item *ent outputJSON, _ := json.Marshal(output) item.OutputData = string(outputJSON) - utils.Error("转存任务项处理失败: %d, 未获取到分享链接", item.ID) + elapsedTime := time.Since(startTime) + utils.Error("转存任务项处理失败: %d, 未获取到分享链接，总耗时: %v", item.ID, elapsedTime) return fmt.Errorf("转存成功但未获取到分享链接") } @@ -161,7 +203,14 @@ func (tp *TransferProcessor) Process(ctx context.Context, taskID uint, item *ent outputJSON, _ := json.Marshal(output) item.OutputData = string(outputJSON) - utils.Info("转存任务项处理完成: %d, 资源ID: %d, 转存链接: %s", item.ID, resourceID, saveURL) + elapsedTime := time.Since(startTime) + utils.InfoWithFields(map[string]interface{}{ + "task_item_id": item.ID, + "resource_id": resourceID, + "save_url": saveURL, + "transfer_duration_ms": transferDuration.Milliseconds(), + "total_duration_ms": elapsedTime.Milliseconds(), + }, "转存任务项处理完成: %d, 资源ID: %d, 转存链接: %s，转存耗时: %v，总耗时: %v", item.ID, resourceID, saveURL, transferDuration, elapsedTime) return nil } diff --git a/utils/logger.go b/utils/logger.go index a360ab9..aebc46e 100644 --- a/utils/logger.go +++ b/utils/logger.go @@ -1,12 +1,14 @@ package utils import ( + "encoding/json" "fmt" "io" "log" "os" "path/filepath" "runtime" + "strings" "sync" "time" ) @@ -40,6 +42,16 @@ func (l LogLevel) String() string { } } +// StructuredLogEntry 结构化日志条目 +type StructuredLogEntry struct { + Timestamp time.Time `json:"timestamp"` + Level string `json:"level"` + Message string `json:"message"` + Caller string `json:"caller"` + Module string `json:"module"` + Fields map[string]interface{} `json:"fields,omitempty"` +} + // Logger 统一日志器 type Logger struct { debugLogger *log.Logger @@ -63,22 +75,72 @@ type LogConfig struct { EnableConsole bool // 是否启用控制台输出 EnableFile bool // 是否启用文件输出 EnableRotation bool // 是否启用日志轮转 + StructuredLog bool // 是否启用结构化日志格式 } // DefaultConfig 默认配置 func DefaultConfig() *LogConfig { + // 从环境变量获取日志级别，默认为INFO + logLevel := getLogLevelFromEnv() + return &LogConfig{ LogDir: "logs", - LogLevel: INFO, + LogLevel: logLevel, MaxFileSize: 100, // 100MB MaxBackups: 5, MaxAge: 30, // 30天 EnableConsole: true, EnableFile: true, EnableRotation: true, + StructuredLog: os.Getenv("STRUCTURED_LOG") == "true", // 从环境变量控制结构化日志 } } +// getLogLevelFromEnv 从环境变量获取日志级别 +func getLogLevelFromEnv() LogLevel { + envLogLevel := os.Getenv("LOG_LEVEL") + envDebug := os.Getenv("DEBUG") + + // 如果设置了DEBUG环境变量为true，则使用DEBUG级别 + if envDebug == "true" || envDebug == "1" { + return DEBUG + } + + // 根据LOG_LEVEL环境变量设置日志级别 + switch strings.ToUpper(envLogLevel) { + case "DEBUG": + return DEBUG + case "INFO": + return INFO + case "WARN", "WARNING": + return WARN + case "ERROR": + return ERROR + case "FATAL": + return FATAL + default: + // 根据运行环境设置默认级别：开发环境DEBUG，生产环境INFO + if isDevelopment() { + return DEBUG + } + return INFO + } +} + +// isDevelopment 判断是否为开发环境 +func isDevelopment() bool { + env := os.Getenv("GO_ENV") + return env == "development" || env == "dev" || env == "local" || env == "test" +} + +// getEnvironment 获取当前环境类型 +func (l *Logger) getEnvironment() string { + if isDevelopment() { + return "development" + } + return "production" +} + var ( globalLogger *Logger onceLogger sync.Once @@ -135,6 +197,11 @@ func NewLogger(config *LogConfig) (*Logger, error) { go logger.startRotationCheck() } + // 打印日志配置信息 + logger.Info("日志系统初始化完成 - 级别: %s, 环境: %s", + config.LogLevel.String(), + logger.getEnvironment()) + return logger, nil } @@ -200,26 +267,55 @@ func (l *Logger) log(level LogLevel, format string, args ...interface{}) { line = 0 } - // 提取文件名 + // 提取文件名作为模块名 fileName := filepath.Base(file) + moduleName := strings.TrimSuffix(fileName, filepath.Ext(fileName)) // 格式化消息 message := fmt.Sprintf(format, args...) // 添加调用位置信息 - fullMessage := fmt.Sprintf("[%s:%d] %s", fileName, line, message) + caller := fmt.Sprintf("%s:%d", fileName, line) + if l.config.StructuredLog { + // 结构化日志格式 + entry := StructuredLogEntry{ + Timestamp: GetCurrentTime(), + Level: level.String(), + Message: message, + Caller: caller, + Module: moduleName, + } + + jsonBytes, err := json.Marshal(entry) + if err != nil { + // 如果JSON序列化失败，回退到普通格式 + fullMessage := fmt.Sprintf("[%s] [%s:%d] %s", level.String(), fileName, line, message) + l.logToLevel(level, fullMessage) + return + } + + l.logToLevel(level, string(jsonBytes)) + } else { + // 普通文本格式 + fullMessage := fmt.Sprintf("[%s] [%s:%d] %s", level.String(), fileName, line, message) + l.logToLevel(level, fullMessage) + } +} + +// logToLevel 根据级别输出日志 +func (l *Logger) logToLevel(level LogLevel, message string) { switch level { case DEBUG: - l.debugLogger.Println(fullMessage) + l.debugLogger.Println(message) case INFO: - l.infoLogger.Println(fullMessage) + l.infoLogger.Println(message) case WARN: - l.warnLogger.Println(fullMessage) + l.warnLogger.Println(message) case ERROR: - l.errorLogger.Println(fullMessage) + l.errorLogger.Println(message) case FATAL: - l.fatalLogger.Println(fullMessage) + l.fatalLogger.Println(message) os.Exit(1) } } @@ -328,15 +424,83 @@ func (l *Logger) cleanOldLogs() { } } -// Close 关闭日志器 -func (l *Logger) Close() error { - l.mu.Lock() - defer l.mu.Unlock() - - if l.file != nil { - return l.file.Close() +// Min 返回两个整数中的较小值 +func Min(a, b int) int { + if a < b { + return a + } + return b +} + +// 结构化日志方法 +func (l *Logger) DebugWithFields(fields map[string]interface{}, format string, args ...interface{}) { + l.logWithFields(DEBUG, fields, format, args...) +} + +func (l *Logger) InfoWithFields(fields map[string]interface{}, format string, args ...interface{}) { + l.logWithFields(INFO, fields, format, args...) +} + +func (l *Logger) WarnWithFields(fields map[string]interface{}, format string, args ...interface{}) { + l.logWithFields(WARN, fields, format, args...) +} + +func (l *Logger) ErrorWithFields(fields map[string]interface{}, format string, args ...interface{}) { + l.logWithFields(ERROR, fields, format, args...) +} + +func (l *Logger) FatalWithFields(fields map[string]interface{}, format string, args ...interface{}) { + l.logWithFields(FATAL, fields, format, args...) +} + +// logWithFields 带字段的结构化日志方法 +func (l *Logger) logWithFields(level LogLevel, fields map[string]interface{}, format string, args ...interface{}) { + if level < l.config.LogLevel { + return + } + + // 获取调用者信息 + _, file, line, ok := runtime.Caller(2) + if !ok { + file = "unknown" + line = 0 + } + + // 提取文件名作为模块名 + fileName := filepath.Base(file) + moduleName := strings.TrimSuffix(fileName, filepath.Ext(fileName)) + + // 格式化消息 + message := fmt.Sprintf(format, args...) + + // 添加调用位置信息 + caller := fmt.Sprintf("%s:%d", fileName, line) + + if l.config.StructuredLog { + // 结构化日志格式 + entry := StructuredLogEntry{ + Timestamp: GetCurrentTime(), + Level: level.String(), + Message: message, + Caller: caller, + Module: moduleName, + Fields: fields, + } + + jsonBytes, err := json.Marshal(entry) + if err != nil { + // 如果JSON序列化失败，回退到普通格式 + fullMessage := fmt.Sprintf("[%s] [%s:%d] %s - Fields: %v", level.String(), fileName, line, message, fields) + l.logToLevel(level, fullMessage) + return + } + + l.logToLevel(level, string(jsonBytes)) + } else { + // 普通文本格式 + fullMessage := fmt.Sprintf("[%s] [%s:%d] %s - Fields: %v", level.String(), fileName, line, message, fields) + l.logToLevel(level, fullMessage) } - return nil } // 全局便捷函数 @@ -359,3 +523,24 @@ func Error(format string, args ...interface{}) { func Fatal(format string, args ...interface{}) { GetLogger().Fatal(format, args...) } + +// 全局结构化日志便捷函数 +func DebugWithFields(fields map[string]interface{}, format string, args ...interface{}) { + GetLogger().DebugWithFields(fields, format, args...) +} + +func InfoWithFields(fields map[string]interface{}, format string, args ...interface{}) { + GetLogger().InfoWithFields(fields, format, args...) +} + +func WarnWithFields(fields map[string]interface{}, format string, args ...interface{}) { + GetLogger().WarnWithFields(fields, format, args...) +} + +func ErrorWithFields(fields map[string]interface{}, format string, args ...interface{}) { + GetLogger().ErrorWithFields(fields, format, args...) +} + +func FatalWithFields(fields map[string]interface{}, format string, args ...interface{}) { + GetLogger().FatalWithFields(fields, format, args...) +}