Java 项目添加慢 SQL 查询工具实践

日期：2026-02-28
场景：校园项目访问 Oracle 数据库，部分查询慢，偶尔出现 Hikari 连接池超时，需要定位慢 SQL 并统计分析。

1️⃣ 背景问题

项目在高并发或大数据量查询时，经常出现：

Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: 
Failed to obtain JDBC Connection; request timed out after 30000ms

初步排查发现：

• Oracle 数据库连接池配置较小，慢 SQL 导致连接占用过久
• 业务查询中存在 LIKE、GROUP BY、分页等操作，大数据量下执行慢

目标：快速定位慢 SQL，统计出现次数和耗时，便于优化。

2️⃣ 工具选型

选择 P6Spy + Logback：

• P6Spy 拦截 JDBC 调用，透明记录 SQL
• 可配置 慢 SQL 阈值（executionThreshold）
• 性能损耗极小

Spring Boot 配置示例

spring:
  datasource:
    driver-class-name: com.p6spy.engine.spy.P6SpyDriver
    url: jdbc:p6spy:oracle:thin:@// **********  /orcl
    username: *********
    password: **********************

spy.properties：

appender=com.p6spy.engine.spy.appender.Slf4JLogger
executionThreshold=1000      # 超过1秒才记录
logMessageFormat=com.p6spy.engine.spy.appender.SingleLineFormat
resultSetLoggable=false

logback.xml：

<appender name="SLOW_SQL_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${LOG_PATH}/slow-sql.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <fileNamePattern>${LOG_PATH}/slow-sql-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
        <maxFileSize>50MB</maxFileSize>
        <maxHistory>30</maxHistory>
    </rollingPolicy>
    <encoder>
        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %msg%n</pattern>
    </encoder>
</appender>

<logger name="p6spy" level="INFO" additivity="false">
    <appender-ref ref="SLOW_SQL_FILE"/>
</logger>

✅ 这样就可以单独输出慢 SQL 到 slow-sql.log，不干扰 info.log、error.log。

3️⃣ 分析思路

慢 SQL 日志样例：

2026-02-28 17:03:13.617 1772269393616|1073|statement|connection 0|url jdbc:p6spy:oracle:thin:@//...|SELECT COUNT(*) ...

字段说明：

字段	含义
1073	SQL 执行耗时（ms）
statement	SQL 类型
connection 0	JDBC 连接编号
SELECT ...	实际执行 SQL

分析方法：

1. 找出耗时 > 阈值的 SQL
2. 判断 SQL 是否包含 LIKE、GROUP BY 或分页
3. 统计出现次数、最大耗时、平均耗时
4. 结合连接池监控判断是否是连接占用导致超时

---

4️⃣ Java 分析工具实现

可以直接在 Java 环境运行，无需 Python。

import java.io.*;
import java.util.*;
import java.util.regex.*;

public class SlowSqlAnalyzer {

    public static void main(String[] args) throws IOException {
        if (args.length < 1) {
            System.out.println("Usage: java SlowSqlAnalyzer <slow-sql.log>");
            return;
        }

        String logFile = args[0];

        // 正则匹配 P6Spy SQL 日志行
        Pattern sqlPattern = Pattern.compile("\\|\\d+\\|statement\\|.*?\\|(SELECT|INSERT|UPDATE|DELETE).*", Pattern.CASE_INSENSITIVE);

        Map<String, SqlStats> statsMap = new HashMap<>();

        try (BufferedReader reader = new BufferedReader(new FileReader(logFile))) {
            String line;
            while ((line = reader.readLine()) != null) {
                String[] parts = line.split("\\|", 6);
                if (parts.length < 6) continue;
                int execTime;
                try {
                    execTime = Integer.parseInt(parts[1]);
                } catch (NumberFormatException e) {
                    continue;
                }
                String sqlText = parts[5].trim();
                Matcher matcher = sqlPattern.matcher(line);
                if (matcher.find()) {
                    // 用前200字符作为 key，避免重复太多
                    String key = sqlText.length() > 200 ? sqlText.substring(0, 200) : sqlText;
                    SqlStats s = statsMap.getOrDefault(key, new SqlStats(sqlText));
                    s.count++;
                    s.totalTime += execTime;
                    s.maxTime = Math.max(s.maxTime, execTime);
                    s.like = s.like || sqlText.toUpperCase().contains("LIKE");
                    s.groupBy = s.groupBy || sqlText.toUpperCase().contains("GROUP BY");
                    statsMap.put(key, s);
                }
            }
        }

        // 输出统计结果
        System.out.printf("%5s | %12s | %12s | %6s | %8s | %s%n",
                "次数", "平均耗时(ms)", "最大耗时(ms)", "LIKE", "GROUP BY", "SQL示例前200字符");
        System.out.println("--------------------------------------------------------------------------------------------------------");

        statsMap.values().stream()
                .sorted((a,b) -> Long.compare(b.totalTime, a.totalTime))
                .forEach(s -> {
                    long avg = s.totalTime / s.count;
                    System.out.printf("%5d | %12d | %12d | %6b | %8b | %s%n",
                            s.count, avg, s.maxTime, s.like, s.groupBy, s.sqlSnippet);
                });
    }

    static class SqlStats {
        String sqlSnippet;
        int count = 0;
        long totalTime = 0;
        long maxTime = 0;
        boolean like = false;
        boolean groupBy = false;

        SqlStats(String sql) {
            this.sqlSnippet = sql;
        }
    }
}

执行方法：

javac SlowSqlAnalyzer.java
java SlowSqlAnalyzer /data/javaApp/rest-tonp-realization/logs/slow-sql.log

输出示例：

次数 | 平均耗时(ms) | 最大耗时(ms) | LIKE | GROUP BY | SQL示例前200字符
--------------------------------------------------------------------------------------------------------
3    | 1234         | 1567         | true | true     | SELECT ... FROM CERTIFICATION ...
2    | 1050         | 1200         | false| true     | SELECT ... FROM PRODUCT_TYPE_NEW ...

---

5️⃣ 收获与优化建议

1. 可视化慢 SQL

   • 统计出现次数、最大耗时、平均耗时
   • 可快速定位热点 SQL

2. SQL 优化方向

   • 对频繁 LIKE 查询字段加索引或改写逻辑
   • 对大数据量 GROUP BY / 分页查询优化（索引 + 分批）
   • 避免长事务占用连接，结合 Hikari 连接池配置

3. 整体收益

   • 每条慢 SQL都可被记录和统计
   • 高并发环境下连接池超时问题更容易排查

---

✅ 总结：
通过 P6Spy + Logback + Java 分析工具，可以快速定位慢 SQL 并统计，为性能优化提供数据支持。