fix

api_routes.py

@@ -198,6 +198,19 @@ if CLIP_AVAILABLE:
 # 创建线程池执行器用于异步处理CPU密集型任务
 executor = ThreadPoolExecutor(max_workers=4)
 
+
+def _log_stage_duration(stage: str, start_time: float, extra: str | None = None) -> float:
+    """
+    统一的耗时日志输出，便于快速定位慢点。
+    """
+    elapsed = time.perf_counter() - start_time
+    if extra:
+        logger.info("耗时统计 | %s: %.3fs (%s)", stage, elapsed, extra)
+    else:
+        logger.info("耗时统计 | %s: %.3fs", stage, elapsed)
+    return elapsed
+
+
 async def process_cpu_intensive_task(func, *args, **kwargs):
     """
     异步执行CPU密集型任务
@@ -1192,28 +1205,42 @@ async def analyze_face(
     valid_image_count = 0
 
     try:
-        t1 = time.perf_counter()
+        overall_start = time.perf_counter()
 
         # 处理每张图片
         for idx, image_data in enumerate(image_data_list):
+            image_start = time.perf_counter()
             try:
+                image_size_kb = len(image_data) / 1024 if image_data else 0
+                decode_start = time.perf_counter()
                 np_arr = np.frombuffer(image_data, np.uint8)
                 image = cv2.imdecode(np_arr, cv2.IMREAD_COLOR)
+                _log_stage_duration(
+                    "图片解码",
+                    decode_start,
+                    f"image_index={idx+1}, size={image_size_kb:.2f}KB, success={image is not None}",
+                )
 
                 if image is None:
                     logger.warning(f"无法解析第{idx+1}张图片")
                     continue
 
                 # 生成MD5哈希
-                original_md5_hash = str(uuid.uuid4()).replace('-', '')
+                original_md5_hash = str(uuid.uuid4()).replace("-", "")
                 original_image_filename = f"{original_md5_hash}_original.webp"
 
                 logger.info(
-                    f"Processing image {idx+1}/{len(image_data_list)}, md5={original_md5_hash}, size={len(image_data) / 1024:.2f} KB"
+                    f"Processing image {idx+1}/{len(image_data_list)}, md5={original_md5_hash}, size={image_size_kb:.2f} KB"
                 )
 
+                analysis_start = time.perf_counter()
                 # 使用指定模型进行分析
                 result = analyzer.analyze_faces(image, original_md5_hash, model)
+                _log_stage_duration(
+                    "模型推理",
+                    analysis_start,
+                    f"image_index={idx+1}, model={model.value}, faces={result.get('face_count', 0)}",
+                )
 
                 # 如果该图片没有人脸，跳过
                 if not result.get("success") or result.get("face_count", 0) == 0:
@@ -1225,9 +1252,15 @@ async def analyze_face(
 
                 if result.get("success") and annotated_image_np is not None:
                     original_image_path = os.path.join(OUTPUT_DIR, original_image_filename)
+                    save_start = time.perf_counter()
                     save_success = save_image_force_compress(
                         annotated_image_np, original_image_path, max_size_kb=100
                     )
+                    _log_stage_duration(
+                        "标注图保存",
+                        save_start,
+                        f"image_index={idx+1}, path={original_image_path}, success={save_success}",
+                    )
 
                     if save_success:
                         result["annotated_image_filename"] = original_image_filename
@@ -1240,25 +1273,26 @@ async def analyze_face(
                             genders: List[Any] = []
                             ages: List[Any] = []
 
-                            for face_info in faces:
-                                beauty_value = float(
-                                    face_info.get("beauty_score") or 0.0)
+                            for face_idx, face_info in enumerate(faces, start=1):
+                                beauty_value = float(face_info.get("beauty_score") or 0.0)
                                 beauty_scores.append(beauty_value)
-                                age_models.append(
-                                    face_info.get("age_model_used"))
-                                gender_models.append(
-                                    face_info.get("gender_model_used"))
+                                age_models.append(face_info.get("age_model_used"))
+                                gender_models.append(face_info.get("gender_model_used"))
                                 genders.append(face_info.get("gender"))
                                 ages.append(face_info.get("age"))
 
-                                cropped_filename = face_info.get(
-                                    "cropped_face_filename")
+                                cropped_filename = face_info.get("cropped_face_filename")
                                 if cropped_filename:
-                                    cropped_path = os.path.join(IMAGES_DIR,
-                                                                cropped_filename)
+                                    cropped_path = os.path.join(IMAGES_DIR, cropped_filename)
                                     if os.path.exists(cropped_path):
-                                        bos_face = upload_file_to_bos(
-                                            cropped_path)
+                                        upload_start = time.perf_counter()
+                                        bos_face = upload_file_to_bos(cropped_path)
+                                        _log_stage_duration(
+                                            "BOS 上传(人脸)",
+                                            upload_start,
+                                            f"image_index={idx+1}, face_index={face_idx}, file={cropped_filename}, uploaded={bos_face}",
+                                        )
+                                        record_face_start = time.perf_counter()
                                         await _record_output_file(
                                             file_path=cropped_path,
                                             nickname=nickname,
@@ -1269,17 +1303,20 @@ async def analyze_face(
                                                 "source": "analyze",
                                                 "role": "face_crop",
                                                 "model": model.value,
-                                                "face_id": face_info.get(
-                                                    "face_id"),
-                                                "gender": face_info.get(
-                                                    "gender"),
+                                                "face_id": face_info.get("face_id"),
+                                                "gender": face_info.get("gender"),
                                                 "age": face_info.get("age"),
                                             },
                                         )
+                                        _log_stage_duration(
+                                            "记录人脸文件",
+                                            record_face_start,
+                                            f"image_index={idx+1}, face_index={face_idx}, file={cropped_filename}",
+                                        )
 
-                            max_beauty_score = max(
-                                beauty_scores) if beauty_scores else 0.0
+                            max_beauty_score = max(beauty_scores) if beauty_scores else 0.0
 
+                            record_annotated_start = time.perf_counter()
                             await _record_output_file(
                                 file_path=original_image_path,
                                 nickname=nickname,
@@ -1291,16 +1328,27 @@ async def analyze_face(
                                     "model": model.value,
                                 },
                             )
+                            _log_stage_duration(
+                                "记录标注文件",
+                                record_annotated_start,
+                                f"image_index={idx+1}, file={original_image_filename}",
+                            )
 
                             # 异步执行图片向量化并入库，不阻塞主流程
                             if CLIP_AVAILABLE:
                                 # 先保存原始图片到IMAGES_DIR供向量化使用
-                                original_input_path = os.path.join(IMAGES_DIR,
-                                                                   original_image_filename)
+                                original_input_path = os.path.join(IMAGES_DIR, original_image_filename)
+                                save_input_start = time.perf_counter()
                                 input_save_success = save_image_high_quality(
-                                    image, original_input_path,
-                                    quality=SAVE_QUALITY)
+                                    image, original_input_path, quality=SAVE_QUALITY
+                                )
+                                _log_stage_duration(
+                                    "原图保存(CLIP)",
+                                    save_input_start,
+                                    f"image_index={idx+1}, success={input_save_success}",
+                                )
                                 if input_save_success:
+                                    record_input_start = time.perf_counter()
                                     await _record_output_file(
                                         file_path=original_input_path,
                                         nickname=nickname,
@@ -1312,13 +1360,26 @@ async def analyze_face(
                                             "model": model.value,
                                         },
                                     )
+                                    _log_stage_duration(
+                                        "��录原图文件",
+                                        record_input_start,
+                                        f"image_index={idx+1}, file={original_image_filename}",
+                                    )
+                                    vector_schedule_start = time.perf_counter()
                                     asyncio.create_task(
                                         handle_image_vector_async(
-                                            original_input_path,
-                                            original_image_filename))
+                                            original_input_path, original_image_filename
+                                        )
+                                    )
+                                    _log_stage_duration(
+                                        "调度向量化任务",
+                                        vector_schedule_start,
+                                        f"image_index={idx+1}, file={original_image_filename}",
+                                    )
 
+                            image_elapsed = time.perf_counter() - image_start
                             logger.info(
-                                f"<-------- Image {idx+1} processing completed, elapsed: {time.perf_counter() - t1:.3f}s, faces={len(faces)}, beauty={beauty_scores}, age={ages} via {age_models}, gender={genders} via {gender_models} --------"
+                                f"<-------- Image {idx+1} processing completed, elapsed: {image_elapsed:.3f}s, faces={len(faces)}, beauty={beauty_scores}, age={ages} via {age_models}, gender={genders} via {gender_models} --------"
                             )
 
                             # 添加到结果列表
@@ -1335,12 +1396,14 @@ async def analyze_face(
         # 如果没有有效图片，返回错误
         if valid_image_count == 0:
             logger.info("<-------- All images processing completed, no faces detected in any image --------")
-            return JSONResponse(content={
-                "success": False,
-                "message": "请尝试上传清晰、无遮挡的正面照片",
-                "face_count": 0,
-                "faces": []
-            })
+            return JSONResponse(
+                content={
+                    "success": False,
+                    "message": "请尝试上传清晰、无遮挡的正面照片",
+                    "face_count": 0,
+                    "faces": [],
+                }
+            )
 
         # 合并所有结果
         combined_result = {
@@ -1350,11 +1413,11 @@ async def analyze_face(
             "faces": [
                 {
                     "face": face,
-                    "annotated_image_filename": result.get("annotated_image_filename")
+                    "annotated_image_filename": result.get("annotated_image_filename"),
                 }
                 for result in all_results
                 for face in result["faces"]
-            ]
+            ],
         }
 
         # 保底：对女性年龄进行调整（如果年龄大于阈值且尚未调整）
@@ -1384,7 +1447,10 @@ async def analyze_face(
 
         # 转换所有 numpy 类型为原生 Python 类型
         cleaned_result = convert_numpy_types(combined_result)
-        logger.info(f"<-------- All images processing completed, total time: {time.perf_counter() - t1:.3f}s, valid images: {valid_image_count} --------")
+        total_elapsed = time.perf_counter() - overall_start
+        logger.info(
+            f"<-------- All images processing completed, total time: {total_elapsed:.3f}s, valid images: {valid_image_count} --------"
+        )
         return JSONResponse(content=cleaned_result)
 
     except Exception as e: