震惊JDBC查询比MyBatis查询快?
文章编写起始原因,在编写项目的时候碰到一个深坑,JDBC获取5000条数据,居然耗时261s,MyBatis同样的操作,耗时12s左右,震惊。看到这里下巴都快掉下来了。不是网上都说MyBatis就是封装了的JDBC吗?不是都说JDBC比MyBatis快很多很多吗?为啥这里却别这么大?
先上图,看看查询的具体情况吧
具体的代码如下:
private List<String> selectTransferData() {
List<String> list = new ArrayList<>();
ResultSet rs;
Statement stmt;
Connection newConn;
try {
newConn = druidDataSource.getConnection();
stmt = newConn.createStatement();
stmt.setFetchSize(Integer.MIN_VALUE);
rs = stmt.executeQuery(sql);
} catch (SQLException e) {
logger.error("traceId: {}, mysql executeQuery error!!! error msg: {}", traceId, e.getMessage());
throw new DataMigrationException(DataMigrationConstant.MYSQL_EXECUTE_QUERY_ERROR);
}
String[] cloumnSplit = transferInsertConfig.getTableCloumnName().split(",");
try {
while (rs.next()) {
StringBuilder data = new StringBuilder("(");
for (int i = 0; i < cloumnSplit.length; i++) {
String cloumnName = cloumnSplit[i].replaceAll(" ", "");
String string = rs.getString(cloumnName);
data.append(string).append(", ");
}
String dataStr = data.substring(0, data.length() - 2) + ")\r\n";
list.add(dataStr);
}
} catch (Exception e) {
logger.error("traceId: {}, 获取查询结果集异常!!! error msg: {}", traceId, e.getMessage());
throw new DataMigrationException("获取查询结果集异常, 异常信息:" + e.getMessage());
} finally {
try {
if (rs != null) {
rs.close();
}
if (stmt != null) {
stmt.close();
}
if (newConn != null) {
newConn.close();
}
} catch (Exception e) {
logger.error("traceId: {}, close io error!!! error msg: {}", traceId, e.getMessage());
}
}
return list;
}
代码里面执行的SQL如下:
SELECT * FROM books WHERE id > 3000000 LIMIT offset, length;
-- offset: 150000 start
-- length: 5000
由于代码执行过慢,这里对代码进行了添加日志观察,看看到底慢在了哪里。根据网上查询的资料来看,应该就是慢在了SQL,实际跟踪下来的结果如下:
关键代码 | 执行时间 | 预期结果 | 实际结果 | 备注 |
---|---|---|---|---|
newConn = druidDataSource.getConnection(); | 30ms | 快 | 很快 | 符合预期结果 |
rs = stmt.executeQuery(sql); | 12.6s | 慢 | 可以接收的慢 | 不符合260s的预期 |
while (rs.next()) { … } | 252s | 快 | 慢 | 超出预料了 |
根据这个结果,又在网上找了很久,基本总结下来就就是SQL慢,rs.next()慢是错觉。然后博主又做了10组sql的查询结果如下:
SQL | 执行时间 | 表数据量 |
---|---|---|
SELECT * FROM books WHERE id > 3000000 LIMIT 300000, 5000 | 12.576s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 305000, 5000 | 12.879s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 310000, 5000 | 15.952s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 315000, 5000 | 15.541s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 320000, 5000 | 13.110s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 325000, 5000 | 12.691 | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 330000, 5000 | 16.411s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 335000, 5000 | 11.809s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 340000, 5000 | 9.461s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 345000, 5000 | 10.374s | > 350w |
直接执行SQL和上面日志跟踪到的执行时间出入不大,于是准备使用mybaits来看测试看看,测试代码如下
IntStream.range(1, 11).forEach(it -> {
long l = System.currentTimeMillis();
booksMapper.getLimit(it * 5000 + 300000);
long l1 = System.currentTimeMillis();
System.out.println("耗时:" + (l1 - l) / 1000 + "s");
});
List<Books> getLimit(int offset);
<select id="getLimit" resultMap="BaseResultMap" parameterType="int">
SELECT * FROM books WHERE id > 3000000 limit #{offset}, 5000
</select>
执行结果如下:
SQL | 执行时间 | 表数据量 |
---|---|---|
SELECT * FROM books WHERE id > 3000000 LIMIT 305000, 5000 | 10.301s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 310000, 5000 | 11.130s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 315000, 5000 | 12.417s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 320000, 5000 | 13.588s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 325000, 5000 | 13.810s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 330000, 5000 | 13.968s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 335000, 5000 | 18.056s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 340000, 5000 | 11.202s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 345000, 5000 | 18.017s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 350000, 5000 | 16.619s | > 350w |
看到这里的时候跟JDBC对比,发现如果仅仅只是SQL执行跟MyBatis比较,真的没有很大出入。但是MyBatis其实不仅查询了数据,而且还做了数据的封装并且返回。JDBC这里也是做了封装的,为啥差别这么大。真的是代码问题吗?好像结果已经不言而喻了。博主还是不太敢相信,决定在调整一下代码,调整代码如下:
while (rs.next()) {
// 删除了处理逻辑,这样就不会是封装返回值影响了
}
实际调用结果如下:
执行第几次 | 执行时间 | 表数据量 |
---|---|---|
1 | 200s | > 350w |
2 | 180s | > 350w |
3 | 165s | > 350w |
4 | 185s | > 350w |
5 | 193s | > 350w |
6 | 184s | > 350w |
7 | 178s | > 350w |
8 | 162s | > 350w |
9 | 180s | > 350w |
10 | 191s | > 350w |
这是不是已经铁的事实,就是拼接问题?不见得吧。比较下来,拼接问题看来并不是很大。耗时还是再rs.next上。
rs.next()的实现就是光标的移动,光标的移动仅仅只是位置的偏移而已,并不产生很多的消耗。这个时候只能提出假设了,假设rs.next并不仅仅是走了光标而且还在数据库内做了什么,并且与我们的SQL有关,那我们SQL本身很慢的话,那这种现状就有解释。于是对SQL调整,调整如下:
SELECT * FROM books a INNER JOIN( SELECT * FROM books WHERE id > 3000000 LIMIT 255000, 5000 ) b ON a.id = b.id
先SQL执行测试10组试试:
执行结果如下:
SQL | 执行时间 | 表数据量 |
---|---|---|
SELECT * FROM books WHERE id > 3000000 LIMIT 305000, 5000 | 4.662s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 310000, 5000 | 4.966s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 315000, 5000 | 4.407s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 320000, 5000 | 4.276s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 325000, 5000 | 4.199s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 330000, 5000 | 4.422s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 335000, 5000 | 4.282s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 340000, 5000 | 3.819s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 345000, 5000 | 3.813s | > 350w |
SELECT * FROM books WHERE id > 3000000 LIMIT 350000, 5000 | 3.666s | > 350w |
看起来快了比之前SQL执行快了两倍还要多。不过这里有个问题,我们执行SQL的时候,如果是在客户端里面执行的,他会自动限定查询的返回结果,比如:固定显示200条,其实就是limit 200,这个条件导致我们测试不是那么的准。所以还是继续走程序
先将之前的代码恢复到最开始的状态,然后用这个调整的SQL走10组试试
执行第几次 | 执行时间 | 表数据量 |
---|---|---|
1 | 629.969s | > 350w |
2 | 607.075s | > 350w |
3 | 660.476s | > 350w |
4 | 653.261s | > 350w |
5 | 679.521s | > 350w |
6 | 611.962s | > 350w |
7 | 598.981s | > 350w |
8 | 604.788s | > 350w |
9 | 651.673s | > 350w |
10 | 650.522s | > 350w |
事实证明,就是优化的SQL在客户端执行看似有用,实际程序内运行,慢了3倍。
JDBC查询比MyBatis慢在哪里?
真的是rs.next吗?
------------------------------------> 待续