YG_FT/backend/app/core/op_log.py

"""
操作日志工具模块

提供 @op_log 装饰器和 log_operation 函数，用于记录用户在各业务模块的详细操作。
自动捕获成功/失败状态、完整报错堆栈、操作耗时等。

核心设计：
  - 失败操作必须清晰记录完整异常堆栈（traceback）
  - 记录异常类型（如 RuntimeError / ValueError / ConnectionError）
  - 记录具体出错的函数名和文件位置，方便定位 bug
  - 记录 HTTP 状态码，方便区分用户错误(4xx)和系统错误(5xx)

使用示例：
    from app.core.op_log import op_log, OpModule, OpAction

    @router.post("/inference/start")
    @op_log(module=OpModule.INFERENCE, action=OpAction.START, target_type="inference")
    async def start_inference(...):
        ...
"""

from __future__ import annotations

import asyncio
import functools
import json
import time
import traceback
from datetime import datetime, timezone
from typing import Any, Callable, Optional, TypeVar

from fastapi import Request

from app.core.logging import get_logger, get_structured_logger, request_id_var
from app.db.platform_store import get_platform_store, new_id, utcnow

logger = get_logger("app.op_log")
biz_logger = get_structured_logger("app.biz")

F = TypeVar("F", bound=Callable[..., Any])


class OpModule:
    """业务模块常量"""
    FINE_TUNE = "fine-tune"           # 模型训练
    MODEL_EVAL = "model-eval"         # 模型评测
    INFERENCE = "model-inference"     # 模型推理
    MODEL_MANAGE = "model-manage"     # 模型管理
    DATASET = "dataset"               # 数据集
    DATA_PROCESS = "data-process"    # 数据处理
    DATA_CONVERT = "data-convert"     # 数据类型转换
    COMPUTE = "compute"              # 算力节点
    SYSTEM = "system"                # 系统


class OpAction:
    """操作动作常量"""
    CREATE = "create"
    UPDATE = "update"
    DELETE = "delete"
    START = "start"
    STOP = "stop"
    UPLOAD = "upload"
    DOWNLOAD = "download"
    CONVERT = "convert"
    MERGE = "merge"
    IMPORT = "import"
    LOGIN = "login"
    LOGOUT = "logout"
    PUBLISH = "publish"
    RETRY = "retry"


class OpStatus:
    """操作状态常量"""
    SUCCESS = "success"
    FAILURE = "failure"


def op_log(
    module: str,
    action: str,
    target_type: str = "",
    *,
    target_name_param: str = "name",
    detail_params: Optional[list[str]] = None,
) -> Callable[[F], F]:
    """
    操作日志装饰器

    自动记录：
    - 谁在什么时间操作了什么
    - 成功还是失败
    - 失败时记录完整异常堆栈(traceback)、异常类型、异常消息
    - 出错的函数名和文件位置，方便定位 bug
    - 操作耗时(ms)
    - 客户端 IP、请求路径

    Args:
        module: 业务模块（OpModule 常量）
        action: 操作动作（OpAction 常量）
        target_type: 资源类型
        target_name_param: 从 kwargs 中提取目标名称的参数名
        detail_params: 需要记录到 detail 的参数名列表
    """
    def decorator(func: F) -> F:
        func_name = f"{func.__module__}.{func.__qualname__}"

        if asyncio.iscoroutinefunction(func):
            @functools.wraps(func)
            async def async_wrapper(*args, **kwargs):
                started_at = time.perf_counter()
                trace_id = request_id_var.get("-")

                user = _extract_user(args, kwargs)
                request = _extract_request(args)

                target_name = _get_param(kwargs, target_name_param, "")
                target_id = _get_param(kwargs, "task_id", "") or _get_param(kwargs, "dataset_id", "") or _get_param(kwargs, "model_id", "")

                detail_dict = _build_detail(detail_params, kwargs)
                detail_str = json.dumps(detail_dict, ensure_ascii=False) if detail_dict else ""

                try:
                    result = await func(*args, **kwargs)
                    elapsed_ms = (time.perf_counter() - started_at) * 1000

                    if not target_id and isinstance(result, dict):
                        target_id = str(result.get("id", ""))

                    _write_log(
                        module=module,
                        action=action,
                        target_type=target_type,
                        target_id=str(target_id) if target_id else None,
                        target_name=str(target_name) if target_name else None,
                        status=OpStatus.SUCCESS,
                        error_message="",
                        error_type="",
                        error_traceback="",
                        func_name=func_name,
                        detail=detail_str,
                        user=user,
                        request=request,
                        trace_id=trace_id,
                        duration_ms=elapsed_ms,
                    )
                    return result

                except Exception as exc:
                    elapsed_ms = (time.perf_counter() - started_at) * 1000

                    # 捕获完整异常堆栈
                    tb_lines = traceback.format_exception(type(exc), exc, exc.__traceback__)
                    full_traceback = "".join(tb_lines)
                    error_msg = str(exc)[:1000]
                    error_type = type(exc).__name__

                    _write_log(
                        module=module,
                        action=action,
                        target_type=target_type,
                        target_id=str(target_id) if target_id else None,
                        target_name=str(target_name) if target_name else None,
                        status=OpStatus.FAILURE,
                        error_message=error_msg,
                        error_type=error_type,
                        error_traceback=full_traceback,
                        func_name=func_name,
                        detail=detail_str,
                        user=user,
                        request=request,
                        trace_id=trace_id,
                        duration_ms=elapsed_ms,
                    )
                    raise

            return async_wrapper  # type: ignore
        else:
            @functools.wraps(func)
            def sync_wrapper(*args, **kwargs):
                started_at = time.perf_counter()
                trace_id = request_id_var.get("-")

                user = _extract_user(args, kwargs)
                request = _extract_request(args)

                target_name = _get_param(kwargs, target_name_param, "")
                target_id = _get_param(kwargs, "task_id", "") or _get_param(kwargs, "dataset_id", "") or _get_param(kwargs, "model_id", "")

                detail_dict = _build_detail(detail_params, kwargs)
                detail_str = json.dumps(detail_dict, ensure_ascii=False) if detail_dict else ""

                try:
                    result = func(*args, **kwargs)
                    elapsed_ms = (time.perf_counter() - started_at) * 1000

                    if not target_id and isinstance(result, dict):
                        target_id = str(result.get("id", ""))

                    _write_log(
                        module=module,
                        action=action,
                        target_type=target_type,
                        target_id=str(target_id) if target_id else None,
                        target_name=str(target_name) if target_name else None,
                        status=OpStatus.SUCCESS,
                        error_message="",
                        error_type="",
                        error_traceback="",
                        func_name=func_name,
                        detail=detail_str,
                        user=user,
                        request=request,
                        trace_id=trace_id,
                        duration_ms=elapsed_ms,
                    )
                    return result

                except Exception as exc:
                    elapsed_ms = (time.perf_counter() - started_at) * 1000

                    tb_lines = traceback.format_exception(type(exc), exc, exc.__traceback__)
                    full_traceback = "".join(tb_lines)
                    error_msg = str(exc)[:1000]
                    error_type = type(exc).__name__

                    _write_log(
                        module=module,
                        action=action,
                        target_type=target_type,
                        target_id=str(target_id) if target_id else None,
                        target_name=str(target_name) if target_name else None,
                        status=OpStatus.FAILURE,
                        error_message=error_msg,
                        error_type=error_type,
                        error_traceback=full_traceback,
                        func_name=func_name,
                        detail=detail_str,
                        user=user,
                        request=request,
                        trace_id=trace_id,
                        duration_ms=elapsed_ms,
                    )
                    raise

            return sync_wrapper  # type: ignore

    return decorator


def log_operation(
    *,
    module: str,
    action: str,
    target_type: str = "",
    target_id: str = "",
    target_name: str = "",
    status: str = OpStatus.SUCCESS,
    error_message: str = "",
    error_type: str = "",
    error_traceback: str = "",
    detail: str = "",
    func_name: str = "",
    user: Optional[dict] = None,
    request: Optional[Request] = None,
    duration_ms: float = 0,
) -> None:
    """手动记录操作日志（不方便用装饰器时使用）"""
    trace_id = request_id_var.get("-")
    _write_log(
        module=module,
        action=action,
        target_type=target_type,
        target_id=target_id or None,
        target_name=target_name or None,
        status=status,
        error_message=error_message,
        error_type=error_type,
        error_traceback=error_traceback,
        func_name=func_name,
        detail=detail,
        user=user,
        request=request,
        trace_id=trace_id,
        duration_ms=duration_ms,
    )


def _build_detail(detail_params: Optional[list[str]], kwargs: dict) -> dict:
    """从 kwargs 中提取需要记录的参数"""
    detail_dict = {}
    if detail_params:
        for p in detail_params:
            val = kwargs.get(p)
            if val is not None:
                detail_dict[p] = str(val)[:200]
    return detail_dict


def _extract_user(args: tuple, kwargs: dict) -> Optional[dict]:
    """从函数参数中提取 current_user dict"""
    for arg in args:
        if isinstance(arg, dict) and "id" in arg and "username" in arg:
            return arg
    for v in kwargs.values():
        if isinstance(v, dict) and "id" in v and "username" in v:
            return v
    return None


def _extract_request(args: tuple) -> Optional[Request]:
    """从函数参数中提取 Request 对象"""
    for arg in args:
        if isinstance(arg, Request):
            return arg
    return None


def _get_param(kwargs: dict, key: str, default: str = "") -> str:
    """安全获取参数值"""
    val = kwargs.get(key, default)
    if val is None:
        return default
    return str(val)


def _write_log(
    module: str,
    action: str,
    target_type: str,
    target_id: Optional[str],
    target_name: Optional[str],
    status: str,
    error_message: str,
    error_type: str,
    error_traceback: str,
    func_name: str,
    detail: str,
    user: Optional[dict],
    request: Optional[Request],
    trace_id: str,
    duration_ms: float,
) -> None:
    """写入操作日志到数据库 + 文件日志"""
    user_id = user.get("id") if user else None
    username = user.get("username") if user else None
    client_ip = None
    req_method = None
    req_path = None
    if request:
        client_ip = request.client.host if request.client else None
        req_method = request.method
        req_path = request.url.path

    # ---- 写文件日志（app-biz）----
    log_fields = {
        "bizModule": module,
        "action": action,
        "targetType": target_type or "",
        "targetId": target_id or "",
        "targetName": target_name or "",
        "opStatus": status,
        "durationMs": round(duration_ms, 2),
        "username": username or "",
    }
    if detail:
        log_fields["detail"] = detail[:500]
    if error_message:
        log_fields["errorMessage"] = error_message[:500]
    if error_type:
        log_fields["errorType"] = error_type

    if status == OpStatus.SUCCESS:
        biz_logger.info(f"{module}:{action} {status} - {target_name or target_id or ''}", **log_fields)
    elif status == OpStatus.FAILURE:
        biz_logger.error(f"{module}:{action} {status} - {target_name or target_id or ''} - {error_type}: {error_message[:200]}", **log_fields)

    # ---- 写数据库 ----
    try:
        store = get_platform_store()
        log_id = new_id("op")
        with store.connect() as conn:
            conn.execute(
                """
                INSERT INTO operation_logs
                (id, user_id, username, module, action, target_type, target_id,
                 target_name, status, error_message, error_type, error_traceback,
                 func_name, detail, client_ip,
                 request_method, request_path, trace_id, duration_ms, create_time)
                VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
                """,
                (
                    log_id, user_id, username, module, action,
                    target_type or None, target_id, target_name,
                    status,
                    error_message[:1000] if error_message else None,
                    error_type or None,
                    error_traceback[:5000] if error_traceback else None,
                    func_name or None,
                    detail[:2000] if detail else None,
                    client_ip, req_method, req_path, trace_id,
                    round(duration_ms, 2), utcnow(),
                ),
            )
    except Exception:
        logger.error("写入操作日志到数据库失败 module=%s action=%s", module, action, exc_info=True)