ShardingSphere开启预编译参数insert慢定位

问题背景

用户反馈在使用 ShardingSphere-JDBC 进行批量插入时性能较慢，插入 500 条数据耗时超过 20 秒。
而相同配置下，ShardingSphere-Proxy 执行相同操作则表现正常。

环境信息：

  • MySQL 驱动版本：8.0.22
  • MySQL Server 版本：5.7.38
  • ShardingSphere 版本：5.x

问题现象

初步现象

相同配置下：

  • Proxy 执行：正常（约 1-2 秒）
  • JDBC 执行：很慢（500 条数据超过 20 秒）

通过添加日志确认：慢在 MySQL 驱动执行 SQL 到驱动返回结果这段过程。

疑问点

疑问 1：数据源参数配置相同，为什么 Proxy 不慢而 JDBC 慢？

疑问 2：useServerPrepStmts 和 cachePrepStmts 这两个参数对批量插入的影响是什么？

问题定位

1. 排查思路

1
2
3
4
5
6
问题排查流程：
1. 确认问题现象：Proxy 快，JDBC 慢
2. 添加详细日志：定位具体耗时点（MySQL 驱动执行到返回慢）
3. 抓包分析：确认网络传输和协议层面问题（MySQL Server 处理 execute 慢）
4. 完整测试矩阵：测试多种驱动版本 × MySQL 版本 × 参数组合
5. 根因分析：找到 MySQL 5.7 + useServerPrepStmts=true 参数存在性能瓶颈

2. ShardingSphere-JDBC 添加日志分析

在 JDBCExecutorCallback 中添加执行耗时日志，记录调用 MySQL JDBC 驱动执行 SQL 前后耗时：

1
2
3
4
5
6
7
8
9
10
11
12
private T execute(final JDBCExecutionUnit jdbcExecutionUnit, ...) throws SQLException {
    long startTime = System.currentTimeMillis();
    log.info("execute start, ds: {}, sql length: {}, mode: {}",
            dataSourceName, sqlUnit.getSql().length(), jdbcExecutionUnit.getConnectionMode());
    // 直接调用 MySQL 驱动执行 SQL
    T result = executeSQL(sqlUnit.getSql(), ...);

    long elapsedTime = System.currentTimeMillis() - startTime;
    // 记录 MySQL 驱动执行耗时
    log.info("execute end, ds: {}, time: {} ms", dataSourceName, elapsedTime);
    return result;
}

发现 MySQL 驱动执行 SQL 较慢，初步排除 ShardingSphere 问题。

3. 抓包分析

使用 tcpdump 抓取 MySQL 驱动到 MySQL Server 通信包：

1
2
# 抓取 MySQL 通信包
sudo tcpdump -i any port 3306 -s 0 -w mysql-test.pcap

使用 Wireshark 分析，发现关键问题：

包序号 包类型 描述 耗时
658 COM_STMT_PREPARE 预编译语句 -
17104 COM_STMT_EXECUTE 执行语句（设置 12,000 个参数） -
23415 Response 响应包 MySQL 服务端响应较慢，需要几十秒

关键结论：慢在 COM_STMT_EXECUTE 阶段的参数设置过程，服务端响应异常缓慢。怀疑是 MySQL Server 端问题。

4. 完整测试矩阵验证

测试 4 种驱动版本 × 2 种 MySQL 版本 × 2 种参数组合：

驱动版本 Server 版本 useServerPrepStmts 耗时 (ms) 状态
5.1.49 5.7.38 true 27,182 ⚠️ SLOW (21x)
5.1.49 5.7.38 false 1,303 ✓ 正常
5.1.49 8.0.32 true 1,750 ✓ 正常
5.1.49 8.0.32 false 2,300 ✓ 正常
8.0.22 5.7.38 true 29,291 ⚠️ SLOW (23x)
8.0.22 5.7.38 false 1,257 ✓ 正常
8.0.22 8.0.32 true 1,763 ✓ 正常
8.0.22 8.0.32 false 2,745 ✓ 正常
8.0.33 5.7.38 true 23,553 ⚠️ SLOW (15x)
8.0.33 5.7.38 false 1,563 ✓ 正常
8.0.33 8.0.32 true 1,711 ✓ 正常
8.0.33 8.0.32 false 3,661 ✓ 正常
8.3.0 5.7.38 true 25,844 ⚠️ SLOW (9x)
8.3.0 5.7.38 false 2,846 ✓ 正常
8.3.0 8.0.32 true 1,752 ✓ 正常
8.3.0 8.0.32 false 3,679 ✓ 正常

核心发现：

  1. 问题根源：MySQL 5.7.38 服务端预编译性能瓶颈

    • 所有测试的驱动版本在 MySQL 5.7.38 + useServerPrepStmts=true 时都出现性能问题
    • 性能差距：15-23 倍（25 秒 vs 1-2 秒）

  2. MySQL 8.0.32 无此问题

    • 所有驱动版本在 MySQL 8.0.32 上表现正常

  3. useServerPrepStmts=false 是有效的临时解决方案

    • 在 MySQL 5.7.38 上，设置 useServerPrepStmts=false 后所有版本都恢复正常

5. 为什么 Proxy 不慢而 JDBC 慢？

通过分析连接参数发现：

Proxy 场景：

  • 应用连接 Proxy 的 URL 没有指定 useServerPrepStmts=true,此时 Proxy 默认按照普通 Statement 执行（不走预编译）
  • Proxy → MySQL 的 URL 里的 useServerPrepStmts 参数失效（因为使用的普通 statement）

JDBC 场景：

  • 应用使用 prepared statement
  • 实际 ShardingSphere-JDBC 在存储单元的 HikariCP 连接池 dataSourceProperties 会自动添加 useServerPrepStmts=true 和 cachePrepStmts=true
  • ShardingSphere-JDBC 通过上面预编译参数通过 MySQL 驱动连接 MySQL Server，触发了预编译性能问题

如何让 Proxy 复现同样的 JDBC 慢问题：
如果应用连接 Proxy 时显式指定 useServerPrepStmts=true，Proxy 也会创建 PreparedStatement 并在 MySQL URL 里添加该参数，同样会触发 MySQL bug 执行慢。

根因分析

MySQL Bug #73056

Bug 链接：https://bugs.mysql.com/bug.php?id=73056

问题描述：当 binlog、general log 或 slow query log 启用时，MySQL 5.7 在处理 prepared statement 时会生成完整的 SQL 用于日志记录，而生成过程使用了极低效的 String::replace() 算法。

性能影响：50 倍慢（实际测试 15-23 倍，完全吻合）

调用栈分析

1
2
3
4
5
6
7
dispatch_command
 └─ mysqld_stmt_execute
     └─ Prepared_statement::execute_loop
         └─ Prepared_statement::set_parameters (98.6%)
             └─ insert_params_with_log (98.6%)
                 └─ String::replace (98.1%)
                     └─ bmove_upp (97.9%)

问题根源：insert_params_with_log() 函数使用 String::replace() 逐个替换参数，每次替换都会：

  1. 重新分配字符串缓冲区
  2. 复制整个字符串
  3. 复制参数值

对于 12,000 个参数（500 条 × 24 字段），这意味着 12,000 次内存重分配和字符串复制！

本地测试验证

使用原生 MySQL JDBC 驱动直接测试，复现问题：

1
2
3
4
5
6
7
8
String sql = "INSERT INTO table (col1, col2, ...) VALUES ";
for (int i = 0; i < 500; i++) {
    sql += "(?, ?, ..., ?),";  // 24 个占位符
}

PreparedStatement pstmt = conn.prepareStatement(sql);
// 设置 12,000 个参数
pstmt.executeUpdate();  // 这里会卡住 20+ 秒

必须开启 --slow_query_log=1 参数才会出现该问题，这与 Bug #73056 的描述完全一致。

Perf 性能分析

为了进一步验证根因，使用 perf 工具对 Docker 容器中的 MySQL 5.7.38 进行 CPU 性能分析。

1. Perf 抓取方法

1.1 获取容器 PID

1
2
# 获取 MySQL 容器在宿主机的 PID
docker inspect -f '{{.State.Pid}}' mysql-57-test

1.2 使用 perf 抓取性能数据

1
2
3
4
5
6
7
# 抓取 60 秒性能数据
sudo perf record -F 99 -p <容器PID> -g -- sleep 60

# 参数说明：
# -F 99: 每秒采样 99 次
# -p: 指定进程 PID
# -g: 记录调用栈

在抓取期间执行慢的 SQL（触发预编译 bug）。

1.3 生成报告

1
2
3
4
5
6
7
# 生成文本报告
sudo perf report --stdio > perf-report.txt

# 生成火焰图
sudo perf script | \
    ~/FlameGraph/stackcollapse-perf.pl | \
    ~/FlameGraph/flamegraph.pl > flamegraph.svg

2. 实际性能分析结果

2.1 抓取信息

项目 值
容器名称 mysqlv5-3306-temp
目标进程 mysqld
抓取时长 60 秒
总采样数 463K 样本
总事件数 ~4615 亿 CPU 周期

2.2 核心性能瓶颈

🔴 瓶颈 1: 内存拷贝 (27.61%)

1
__memcpy_ssse3   27.61%

调用栈：

1
2
3
4
5
6
Prepared_statement::insert_params()
  → String::mem_realloc()
    → String::replace()
      → Prepared_statement::set_parameters()
        → Prepared_statement::execute_loop()
          → mysqld_stmt_execute()

问题：Prepared Statement 参数插入时频繁进行内存重新分配和拷贝。

🔴 瓶颈 2: 内存页管理开销 (~40% 内核占用)

函数 占比 说明
clear_page_erms 8.41% 清零内存页
do_anonymous_page 3.47% 匿名页分配
__mod_memcg_lruvec_state 3.42% 内存 cgroup 状态修改
__handle_mm_fault 2.69% 处理内存缺页错误
rmqueue 1.75% 页分配器队列操作
handle_mm_fault 1.53% 内存故障处理

问题：频繁的内存分配导致大量页错误和 cgroup 开销。

🔴 瓶颈 3: 大量页错误 (Page Fault)

  • exc_page_fault (1.64%)
  • do_user_addr_fault (1.71%)
  • handle_pte_fault (0.77%)

2.3 性能分析结论

通过实际 perf 分析验证：

  1. String::mem_realloc() 被频繁调用，每次都需要 memcpy 大量数据（27.61% CPU 消耗）
  2. 频繁的内存分配导致内核页错误处理开销巨大（约 40% 内核占用）
  3. 内存 cgroup 统计修改 也占用了 3.42% 的 CPU

这与 Bug #73056 的描述完全吻合：MySQL 5.7 在处理批量 INSERT 时的 Prepared Statement 参数处理存在严重的性能问题。

3. 火焰图分析

生成的火焰图清晰显示了性能瓶颈：

  • 最宽的栈：String::replace 和 __memcpy_ssse3
  • 调用路径：dispatch_command → mysqld_stmt_execute → Prepared_statement::set_parameters → String::replace
  • 颜色深度：内核函数（内存管理）占比极高

火焰图 X 轴表示样本数量，Y 轴表示调用栈深度。String::replace 及其相关的内存拷贝函数占据了火焰图的绝大部分宽度，直观展示了性能瓶颈所在。

解决方案

方案 操作 优点 缺点 推荐度
方案 1 useServerPrepStmts=false 立即生效 无法使用服务端预编译优化 ⭐⭐⭐⭐
方案 2 升级到 MySQL 8.0.x 彻底解决，可使用预编译优化 需要数据库升级 ⭐⭐⭐⭐⭐
方案 3 关闭 slow_query_log 等日志 可能生效 影响审计和恢复 ⭐⭐

方案 1：关闭服务端预编译（推荐临时方案）

修改 JDBC URL：

1
2
3
4
5
# 原配置（有问题）
jdbc:mysql://localhost:3306/db?...&useServerPrepStmts=true&cachePrepStmts=true

# 修改为
jdbc:mysql://localhost:3306/db?...&useServerPrepStmts=false&cachePrepStmts=true

效果：立即解决性能问题，insert 耗时从 20+ 秒降至 1-3 秒。

说明：

  • useServerPrepStmts=false 时，PreparedStatement 和普通 Statement 一样，在客户端拼接 SQL 语句
  • 不会触发 MySQL 5.7 的服务端预编译 bug

方案 2：升级 MySQL（推荐长期方案）

升级到 MySQL 8.0.x 后，可以继续使用 useServerPrepStmts=true：

1
jdbc:mysql://localhost:3306/db?...&useServerPrepStmts=true&cachePrepStmts=true

MySQL 8.0 对此进行了优化：

  1. 修复了 Bug #73056
  2. 重写了 insert_params_with_log() 算法
  3. 预分配缓冲区，避免重复 realloc
  4. 反向处理参数，避免重复复制

总结

问题定位完成 ✅

层级 问题 状态
应用层 ShardingSphere JDBC ✅ 排除
驱动层 MySQL Connector/J ✅ 排除
网络层 TCP 传输 ✅ 排除
协议层 Prepared Statement 协议 ✅ 确认
MySQL 层 Bug #73056 ✅ 确认

技术细节

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
┌────────────────────────────────────────────────────────────────┐
│  MySQL 5.7 Prepared Statement 执行流程（日志启用时）              │
├────────────────────────────────────────────────────────────────┤
│                                                                 │
│  1. 客户端发送: COM_STMT_PREPARE "INSERT ... VALUES (?, ?, ?)"  │
│  2. 服务端返回: Prepared Statement OK                           │
│  3. 客户端发送: COM_STMT_EXECUTE + 参数 (12,000 个)             │
│  4. 服务端处理:                                                  │
│     ├─ 准备执行语句                                              │
│     ├─ [慢点] set_parameters():                                  │
│     │   └─ insert_params_with_log():                             │
│     │       └─ 对每个 ?: String::replace() ← 这里慢！            │
│     │           ├─ realloc()  ← 内存重分配                      │
│     │           ├─ memcpy()    ← 复制整个字符串                 │
│     │           └─ strcpy()    ← 复制参数值                     │
│     │       └─ 重复 12,000 次！                                   │
│     ├─ 执行语句                                                  │
│     └─ 记录日志（如果需要）                                      │
│                                                                 │
└────────────────────────────────────────────────────────────────┘

时间分布:
  String::replace():  98.1% ████████████████████████████████████
  实际执行:           1.9%  █

参考