update: 日志优化

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
 }
 

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
 }
 

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
 }