如何仅在特定方法/流程中记录SQL语句执行时间？

我之前也碰到过类似的困扰——全量记录SQL执行时间确实会平白增加性能开销，尤其是在高并发场景下，完全没必要。下面几个方案可以帮你精准控制，只在特定方法或流程里记录指定SQL的执行时间：

1. 自定义注解 + AOP（面向切面编程） #

这是Spring生态下最推荐的方案，侵入性极低，还能灵活控制追踪范围。

首先定义一个自定义注解，用来标记需要追踪SQL时间的方法，甚至可以指定要追踪的SQL ID：

@Target({ElementType.METHOD, ElementType.TYPE})
@Retention(RetentionPolicy.RUNTIME)
public @interface TrackSqlTime {
    // 可选参数：指定要追踪的SQL ID列表，空则追踪该方法内所有SQL
    String[] sqlIds() default {};
}

然后编写一个切面类，拦截带有这个注解的方法，在SQL执行前后计算耗时。如果要精准到特定SQL，可以结合ORM框架（比如MyBatis）的上下文获取当前执行的SQL ID，和注解里的列表对比：

@Aspect
@Component
public class SqlTimeTrackingAspect {
    private static final Logger logger = LoggerFactory.getLogger(SqlTimeTrackingAspect.class);

    @Around("@annotation(trackSqlTime)")
    public Object trackSqlExecutionTime(ProceedingJoinPoint joinPoint, TrackSqlTime trackSqlTime) throws Throwable {
        // 用ThreadLocal存储当前方法要追踪的SQL ID列表
        Set<String> targetSqlIds = new HashSet<>(Arrays.asList(trackSqlTime.sqlIds()));
        SqlTrackingContext.setTargetSqlIds(targetSqlIds);
        
        long startTime = System.currentTimeMillis();
        Object result = joinPoint.proceed();
        long totalTime = System.currentTimeMillis() - startTime;
        
        logger.info("方法[{}]中指定SQL总执行耗时：{}ms", joinPoint.getSignature().getName(), totalTime);
        
        SqlTrackingContext.clear();
        return result;
    }
}

使用时，只需要在目标方法上加上注解即可：

@TrackSqlTime(sqlIds = {"getUserById", "updateUserStatus"})
public void handleUserOperation(Long userId) {
    // 这里执行的 getUserById 和 updateUserStatus 会被记录耗时
    User user = userMapper.selectById(userId);
    userMapper.updateStatus(userId, UserStatus.ACTIVE);
    // 其他SQL不会被追踪
    logService.saveOperationLog(userId);
}

2. 手动埋点（适合简单小场景） #

如果你的项目没有用AOP，或者只需要在少数几个地方追踪，手动埋点是最直接的方式——虽然侵入性强胜在简单。

直接在需要追踪的SQL执行前后记录时间：

public User getUserWithOrders(Long userId) {
    // 追踪这个SQL的耗时
    long start = System.currentTimeMillis();
    User user = userMapper.selectById(userId);
    long end = System.currentTimeMillis();
    logger.info("SQL [getUserById] 执行耗时：{}ms", end - start);
    
    // 这个SQL不需要追踪
    List<Order> orders = orderMapper.listByUserId(userId);
    user.setOrders(orders);
    return user;
}

3. ORM框架自定义插件（精准到单条SQL） #

如果你用MyBatis、Hibernate这类ORM框架，可以通过扩展插件的方式，精准控制哪些SQL需要记录时间，同时结合ThreadLocal标记当前是否处于追踪流程中。

以MyBatis为例：
首先写一个上下文工具类，用来开启/关闭追踪，并指定要追踪的SQL ID：

public class SqlTrackingContext {
    private static final ThreadLocal<Set<String>> TRACKED_SQL_IDS = new ThreadLocal<>();

    public static void startTracking(String... sqlIds) {
        TRACKED_SQL_IDS.set(new HashSet<>(Arrays.asList(sqlIds)));
    }

    public static void stopTracking() {
        TRACKED_SQL_IDS.remove();
    }

    public static boolean shouldTrack(String sqlId) {
        Set<String> ids = TRACKED_SQL_IDS.get();
        return ids != null && ids.contains(sqlId);
    }
}

然后编写MyBatis插件，拦截SQL执行：

@Intercepts({
    @Signature(type = Executor.class, method = "query", args = {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class}),
    @Signature(type = Executor.class, method = "update", args = {MappedStatement.class, Object.class})
})
public class SqlTimeTrackingPlugin implements Interceptor {
    private static final Logger logger = LoggerFactory.getLogger(SqlTimeTrackingPlugin.class);

    @Override
    public Object intercept(Invocation invocation) throws Throwable {
        MappedStatement ms = (MappedStatement) invocation.getArgs()[0];
        String sqlId = ms.getId();
        
        if (SqlTrackingContext.shouldTrack(sqlId)) {
            long start = System.currentTimeMillis();
            Object result = invocation.proceed();
            long cost = System.currentTimeMillis() - start;
            logger.info("SQL [{}] 执行耗时：{}ms", sqlId, cost);
            return result;
        }
        return invocation.proceed();
    }

    @Override
    public Object plugin(Object target) {
        return Plugin.wrap(target, this);
    }

    @Override
    public void setProperties(Properties properties) {}
}

最后在需要追踪的流程里开启开关：

public void processCriticalOrder(Long orderId) {
    try {
        // 指定要追踪的SQL ID
        SqlTrackingContext.startTracking("getOrderById", "updateOrderPaymentStatus");
        Order order = orderMapper.selectById(orderId);
        orderMapper.updatePaymentStatus(orderId, PaymentStatus.PAID);
        // 其他SQL不会被追踪
        inventoryService.reduceStock(order.getProductId(), order.getQuantity());
    } finally {
        // 一定要关闭追踪，避免内存泄漏
        SqlTrackingContext.stopTracking();
    }
}

4. 基于日志框架的动态过滤（适合已有全量日志的场景） #

如果你的项目已经在全量记录SQL日志，只是不想一直输出耗时，可以用日志框架的MDC（映射诊断上下文）来动态控制。

以Logback为例：
首先在目标方法里设置MDC标记：

public void runHighPriorityTask(Long taskId) {
    MDC.put("trackSqlTime", "true");
    try {
        // 这里的SQL执行会被记录耗时
        taskMapper.executeHighPriorityTask(taskId);
    } finally {
        // 清理MDC标记
        MDC.remove("trackSqlTime");
    }
}

然后在Logback配置文件里添加过滤规则，只有当MDC存在trackSqlTime=true时，才输出SQL耗时日志：

<appender name="SQL_TIME_APPENDER" class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
        <evaluator>
            <expression>MDC.get("trackSqlTime") == "true"</expression>
        </evaluator>
        <onMatch>ACCEPT</onMatch>
        <onMismatch>DENY</onMatch>
    </filter>
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level - SQL [%-30.30logger{30}] 耗时：%X{sqlExecutionTime}ms%n</pattern>
    </encoder>
</appender>

<logger name="your.orm.sql.logger" level="DEBUG" additivity="false">
    <appender-ref ref="SQL_TIME_APPENDER"/>
</logger>

方案选择建议 #

• 如果你用Spring生态：优先选自定义注解+AOP，侵入性低，维护方便；
• 如果你需要精准到单条SQL：选ORM框架插件，控制粒度最细；
• 小范围简单场景：用手动埋点，快速实现；
• 已有全量SQL日志：用MDC动态过滤，无需改动业务代码。

内容的提问来源于stack exchange，提问作者Jay