大家好,我是烤鸭:
有点意思的问题,代码提示接口超时(10s+),接口逻辑很简单,就一个sql查询。本来也想是sql慢,可是拿sql去Navicat执行下,一点不慢(50ms)。
环境
DB:SqlServer
连接池:Druid
ORM:Mybatis
猜想
是刚好那个时段有其他操作造成的阻塞?
有特定参数造成的大量回表?
用了三方插件有bug?skywalking?pagehelper?
尝试复现
这个问题只在生产环境出现,即便是把生产数据备份到测试库,也不能复现。
可能生产库和测试库版本和配置不一样。
原sql
<if test="title != null and title!=''">AND vv.title LIKE CONCAT(CONCAT('%', #{title}), '%')
</if>
同事有人说把参数写死试试,原来的sql类似这样。不慢了,什么原理。
<if test="title != null and title!=''">AND vv.title LIKE CONCAT(CONCAT('%', 'abc'), '%')
</if>
再把#换成$,还是很快。大概就知道要看哪块的源码了。
<if test="title != null and title!=''">AND vv.title LIKE CONCAT(CONCAT('%', '${title}'), '%')
</if>
关于mybatis的#和$,这篇文章写的挺好的,就不再重复了。
https://blog.csdn.net/weixin_43401380/article/details/122504003
源码分析
先说下sql执行的大致流程。
ORM框架(Mybatis做完动态sql之后) —> 连接池插件(Druid) —> JDBC —> DB(Sqlserver)。
下图是以查询方法为例。
接着我们看下源码:
SQLServerPreparedStatement.doPrepExec(执行RPC请求,构建请求sql,以及是否需要参数等)
final void doExecutePreparedStatement(PrepStmtExecCmd command) throws SQLServerException {resetForReexecute();// ...boolean hasExistingTypeDefinitions = preparedTypeDefinitions != null;boolean hasNewTypeDefinitions = true;if (!encryptionMetadataIsRetrieved) {// 动态sql变量初始化hasNewTypeDefinitions = buildPreparedStrings(inOutParam, false);}// ...String dbName = connection.getSCatalog();boolean needsPrepare = true;// Retry execution if existing handle could not be re-used.for (int attempt = 1; attempt <= 2; ++attempt) {try {// 构建 TDSWriter ,指令为TDS的RPCTDSWriter tdsWriter = command.startRequest(TDS.PKT_RPC);// PrepExec 执行needsPrepare = doPrepExec(tdsWriter, inOutParam, hasNewTypeDefinitions, hasExistingTypeDefinitions);// 结果监听ensureExecuteResultsReader(command.startResponse(getIsResponseBufferingAdaptive()));startResults();getNextResult();}catch (SQLException e) {// ...}break;}
}
SQLServerPreparedStatement.buildPreparedStrings(
sql替换,把 ? 转换成 @p1,@p2 这种,比如 mybatis 的转换后是这样的。
AND vv.title LIKE CONCAT(CONCAT('%', @p1), '%')
)
/*** Determines whether the statement needs to be reprepared based on a change in any of the type definitions of any of the parameters due to* changes in scale, length, etc., and, if so, sets the new type definition string.*/
private boolean buildPreparedStrings(Parameter[] params,boolean renewDefinition) throws SQLServerException {String newTypeDefinitions = buildParamTypeDefinitions(params, renewDefinition);if (null != preparedTypeDefinitions && newTypeDefinitions.equals(preparedTypeDefinitions))return false; preparedTypeDefinitions = newTypeDefinitions;/* Replace the parameter marker '?' with the param numbers @p1, @p2 etc */preparedSQL = connection.replaceParameterMarkers(userSQL, params, bReturnValueSyntax);if (bRequestedGeneratedKeys)preparedSQL = preparedSQL + identityQuery;return true;
}
SQLServerPreparedStatement.doPrepExec(调用写SQL和写参数方法)
private boolean doPrepExec(TDSWriter tdsWriter,Parameter[] params,boolean hasNewTypeDefinitions,boolean hasExistingTypeDefinitions) throws SQLServerException {boolean needsPrepare = (hasNewTypeDefinitions && hasExistingTypeDefinitions) || !hasPreparedStatementHandle();// ...else {// Move overhead of needing to do prepare & unprepare to only use cases that need more than one execution.// First execution, use sp_executesql, optimizing for asumption we will not re-use statement.if (needsPrepare && !connection.getEnablePrepareOnFirstPreparedStatementCall() && !isExecutedAtLeastOnce) {// 第一次执行的时候buildExecSQLParams(tdsWriter);isExecutedAtLeastOnce = true;}// Second execution, use prepared statements since we seem to be re-using it.else if(needsPrepare)// 写入sqlbuildPrepExecParams(tdsWriter);elsebuildExecParams(tdsWriter);}// 写入参数sendParamsByRPC(tdsWriter, params);return needsPrepare;
}
SQLServerPreparedStatement.buildPrepExecParams(通过TCP(TDS协议),写入SQL和参数定义)
private void buildPrepExecParams(TDSWriter tdsWriter) throws SQLServerException {if (getStatementLogger().isLoggable(java.util.logging.Level.FINE))getStatementLogger().fine(toString() + ": calling sp_prepexec: PreparedHandle:" + getPreparedStatementHandle() + ", SQL:" + preparedSQL);// ...tdsWriter.writeShort((short) 0xFFFF); // procedure name length -> use ProcIDs// 执行方法是 SP_PREPEXECtdsWriter.writeShort(TDS.PROCID_SP_PREPEXEC);tdsWriter.writeByte((byte) 0); // RPC procedure option 1tdsWriter.writeByte((byte) 0); // RPC procedure option 2// <prepared handle>// IN (reprepare): Old handle to unprepare before repreparing// OUT: The newly prepared handletdsWriter.writeRPCInt(null, getPreparedStatementHandle(), true);resetPrepStmtHandle();// <formal parameter defn> IN,写入参数定义,比如上面的title就是 @P0 NVARCHAR(4000)tdsWriter.writeRPCStringUnicode((preparedTypeDefinitions.length() > 0) ? preparedTypeDefinitions : null);// <stmt> IN,写入SQLtdsWriter.writeRPCStringUnicode(preparedSQL);
}
DTVExecuteOp.execute(执行实际参数的赋值)
void execute(DTV dtv,String strValue) throws SQLServerException {if (null != strValue && strValue.length() > DataTypes.SHORT_VARTYPE_MAX_CHARS)dtv.setJdbcType(JDBCType.LONGNVARCHAR);// 实际的参数setTypeDefinition(dtv);
}
原因猜想
分析了一大顿源码,并没有找到问题所在,同样的SQL在程序执行隔一天就不慢了,不清楚是不是还有别的什么因素影响执行计划。
- 连接规范不同:像数据库client的实现规范有JDBC(针对java语言的)或者ODBC,我们Java服务程序用的JDBC,像navicat这些软件用的是ODBC。导致同样的SQL执行计划不同。
- SqlServer-Client 版本问题,不同版本的client也有不同的优化。
- sp_prepare | sp_execute 带参数执行 和 sp_executesql,生成的执行计划不同。
没找到答案,问题竟然自己消失了,先蹲个点,如果再出现就再研究一下。
总结
当出现这个问题的时候,不要迷,先想想这个题干成立么。
navicat 执行很快,java程序很慢,两边执行的是同一个sql么?
原本在navicat 执行的是(不慢)
SELECT TOP 15 id FROM test where tile like '%测试%'
实际执行的应该是这个 sp_prepare 和 sp_execute的语句(待验证,由于问题消失,没法验证了)
declare @N int
exec sp_prepare @n output,N'@p1 NVARCHAR (4000)',N'SELECT TOP 15 id FROM test where tile like ''%'' + @p1 +''%'' '
exec sp_execute @n,'aaa' --@n就是sp_prepare返回的句柄,使用sp_execute来通过这个句柄来传递参数
如果执行这个 navicat 也变慢了,那就可以推论是 sp_prepare 这种方式导致的。
看了源码还是很难定位问题,越难的问题,解决起来越有意思,等再出现记录一下。
相关文章
JDBC和ODBC区别:
https://www.php.cn/mysql-tutorials-414951.html
DTS协议分析:
https://www.docin.com/p-98157348.html
Sp_prepare | sp_execute 介绍:
https://www.cnblogs.com/gered/p/14648626.html
EXEC和sp_executesql使用介绍:
https://blog.csdn.net/neweastsun/article/details/40019439
SQLServer执行动态SQL:
https://www.gxlcms.com/mssql-350221.html
SQLServer执行计划:
https://www.jianshu.com/p/172a345fee95
常见问题
必须声明标量变量:
https://blog.csdn.net/dxnn520/article/details/17304573