上周五碰到开发的请求协助解决数据预定程序中对单头等几个表检索数据时检索条件尾数是9的数据特别慢。第一时间想到的是否如下几个问题:
1、 数据库相应数据最多;
2、 数据表进行了分区,而相应数据落在的分区性能存在问题;
3、 检索该批记录的会话很多;
但很快排除了以上几种可能,因为后续的调查由如下发现:
1、 查询了相应数据,尾数0-9的数据几乎平均分布;
2、 直接用SQLSERVER查询分析器查询速度很快;
到此大家基本都认为数据库不存在问题,但是如下的调查感觉又让人陷入了迷茫。在相同网段的其他服务器上建立了相应的用户、表、数据进行测试,发现程序取数据速度很快,和生产数据库的区别就是数据量,还有表结构(为了测试偷懒全部字段定义为VARCHAR,后来执行程序异常才迫不得已把部分字段改成了date)。虽然测试过程不严谨,但这又似乎能把问题的天平向数据库这边倾斜。
就这样周末测试摸索的一天很快过去了,家里的无线网络6块钱一小时开销也实在不小,周一一大早就来到公司,回归有限宽带的怀抱,但郁闷的生产库我们只有查询几个字段的权限,我动不了。于是联络上游数据单位,盘算着通过看执行日志等手段把问题范围进一步缩小,而要对方配合却要工作联系单。想想还是先花半天时间有把我们这边的问题可能性全部扫除了才开这个联系单。
如何进一步缩小差距, 接下来来看看网络是否有问题,巧的是数据库服务器IP末尾是9,而恰恰是末尾为9的数据,为了排除该问题,进行了一系列的探索:
1、 更换测试数据库服务器,发现取数据速度正常;
2、 在测试程序客户段增加HOST映射,但取数据速度依旧;
3、在同一网段服务器部署测试程序。
以上三种测试均表明网络异常的可能性越来越小,至少在我们IDC和分中心内网之间的网络互联是正常的。
再镇定想想数据库查询为什么慢,只有三个层面的原因,数据库本身的性能问题、网络问题、客户端问题,而当今问题最多的无疑就是客户端程序异常,既然生产数据库无法做有效的调试,那么我们得把我们的问题尽量扫除。
于是请开发部的侯文杰把相关代码的时间戳进一步细化,文杰几分钟内就提供了代码,立即上传测试发现在ps = conn.prepareStatement和ps.setString效率上均没有问题,而rs = ps.executeQuery();就是罪会祸首。
再来仔细审视数据,一个念头突然闪现,既然SQLSERVER客户端查询正常,会不会是程序组装的SQL存在问题。于是立即要求文杰给我一个测试任意SQL语句的接口,通过这个接口,我可以随心所欲的测试cout(*),like等语句的性能(悲剧的是很长时间没有碰代码,我的开发环境已经无法运行)。一个小时后我得到了这个接口,接下来发现了令人兴奋的结果:
我自己组装的一条完整的SQL语句通过程序装载后执行迅速,而另外一条通过JDBC SETSTRING组装的同样的SQL语句,竟然还是出奇的慢。
测试案例一:
[jdbctest] 2011-05-09 16:03:41,437 - 获得jdbc连接start...
[jdbctest] 2011-05-09 16:03:42,062 - 获得jdbc连接end...
[jdbctest] 2011-05-09 16:03:42,078 - 开始执行自定义Statement动态sql=Select TRYhead0_.TRY_ID As TRY1_0_,TRYhead0_.PRE_TRY_ID As Pre2_122_0_ From Ris.risk.TRY_HEAD TRYhead0_ Where TRYhead0_.TRY_ID = '290120040024700579'-----自己写了完整的SQL语句传入JAVA程序
[jdbctest] 2011-05-09 16:03:42,187 - com.microsoft.sqlserver.jdbc.SQLServerResultSetMetaData@7c6768
[jdbctest] 2011-05-09 16:03:42,203 - ColumnName is=TRY1_0_,and value is=290120040024700579
[jdbctest] 2011-05-09 16:03:42,203 - ColumnName is=Pre2_122_0_,and value is=000000000002748431
[jdbctest] 2011-05-09 16:03:42,203 - 结束执行自定义Statement动态sql,用时:125毫秒
[jdbctest] 2011-05-09 16:03:42,203 - 获得jdbc连接start...
[jdbctest] 2011-05-09 16:03:42,234 - 获得jdbc连接end...
[jdbctest] 2011-05-09 16:03:42,265 - conn.prepareStatement(),DYNAMIC_EXECUTE_PREPARESQL is=Select head0.TRY_ID As TRY1_0,head0.PRE_TRY_ID As Pre2_122_0_ From Ris.risk.TRY_HEAD head0 Where head0.TRY_ID = ?,耗时:62毫秒-----采用JDBC的SETSTRING方法设变量
[jdbctest] 2011-05-09 16:05:15,125 - com.microsoft.sqlserver.jdbc.SQLServerResultSetMetaData@b162d5
[jdbctest] 2011-05-09 16:05:15,125 - ColumnName is=TRY1_0,and value is=290120040014700789
[jdbctest] 2011-05-09 16:05:15,125 - ColumnName is=Pre2_122_0_,and value is=000000000002794232
[jdbctest] 2011-05-09 16:05:15,125 - 结束执行自定义prepare动态sql,用时:92922毫秒
这已经很显然了,JDBC组装的SQL语句有问题的嫌疑最大。
再查相关资料,在sqlserver jdbc 驱动的文档发现里面有这么一个参数:
SendStringParametersAsUnicode
SendStringParametersAsUnicode={true false}. Determines
whether string parameters are sent to the SQL Server database in
Unicode or in the default character encoding of the database.
True means that string parameters are sent to SQL Server in
Unicode. False means that they are sent in the default encoding,
which can improve performance because the server does not need
to convert Unicode characters to the default encoding. You
should, however, use default encoding only if the parameter
string data that you specify is consistent with the default
encoding of the database.
The default is true
string型的参数传到数据库里面默认是转换成unicode的。
马上请文杰进行相关把SendStringParameters属性(参考附件二)设置成false(详见附一),设置后查询的性能得到了巨大的提高,原来用数分钟的查询现在只需要几时毫秒了。
执行结果如下:
测试案例二:
[jdbctest] 2011-05-09 15:42:59,812 - 开始执行自定义Statement动态sql=Select TRYhead0_.TRY_ID As TRY1_0_,TRYhead0_.PRE_TRY_ID As Pre2_122_0_ From Ris.risk.TRY_HEAD TRYhead0_ Where TRYhead0_.TRY_ID = '290120040024700579'
[jdbctest] 2011-05-09 15:42:59,890 - com.microsoft.sqlserver.jdbc.SQLServerResultSetMetaData@7c6768[jdbctest] 2011-05-09 15:42:59,906 - ColumnName is=TRY1_0_,and value is=290120040024700579
[jdbctest] 2011-05-09 15:42:59,906 - ColumnName is=Pre2_122_0_,and value is=000000000002748431
[jdbctest] 2011-05-09 15:42:59,921 - 结束执行自定义Statement动态sql,用时:109毫秒
[jdbctest] 2011-05-09 15:42:59,921 - 获得jdbc连接start...
[jdbctest] 2011-05-09 15:42:59,953 - 获得jdbc连接end...
[jdbctest] 2011-05-09 15:42:59,968 - conn.prepareStatement(),DYNAMIC_EXECUTE_PREPARESQL is=Select head0.TRY_ID As TRY1_0,head0.PRE_TRY_ID As Pre2_122_0_ From Ris.risk.TRY_HEAD head0 Where head0.TRY_ID = ?,耗时:47毫秒
[jdbctest] 2011-05-09 15:42:59,984 - com.microsoft.sqlserver.jdbc.SQLServerResultSetMetaData@b162d5
[jdbctest] 2011-05-09 15:42:59,984 - ColumnName is=TRY1_0,and value is=290120040014700789
[jdbctest] 2011-05-09 15:43:00,000 - ColumnName is=Pre2_122_0_,and value is=000000000002794232
[jdbctest] 2011-05-09 15:43:00,000 - 结束执行自定义prepare动态sql,用时:79毫秒-------------对比测试案例一可以发现速度明显提高
到此JDBC查询已经可以解决问题了,但是我们的程序都是部署在连接池(POOL下的)
查看了下官方文档,我们发现有如下内容:
可以通过多种方式指定连接字符串的属性:
· 当使用 DriverManager 类进行连接时,在连接 URL 中通过“名称=值”属性进行指定。
· 在 DriverManager 类中 Connect 方法的 Properties 参数中通过“名称=值”属性进行指定。
· 在驱动程序数据源的适当的 setter 方法中指定值。
我们可以很偷懒的改如下URL解决上述问题(增加;sendStringParametersAsUnicode=false),这样程序不需要做任何更改,但个人认为测试是否有乱码还是必须的:
zjport.datasource.risk.url=jdbc:sqlserver://192.168.1.9:1433;DatabaseName=Ris;sendStringParametersAsUnicode=false
至此问题已经解决了,但最终是什么原因只有尾数9的数据有问题,最大的嫌疑对象是JDBC驱动存在某个未知的BUG,我们仍然需要做后续的探讨!
附件一:修改JDBC代码的方式(文杰提供)
SendStringParameters设置前:
Class.forName(DRIVER_CLASS_NAME);
conn = DriverManager.getConnection(URL, USERNAME, PASSWORD);
SendStringParameters设置后:
Class.forName(DRIVER_CLASS_NAME);
Properties info = new Properties();
info.put("user", USERNAME);
info.put("password", PASSWORD);
info.put("sendStringParametersAsUnicode", "false");
conn = DriverManager.getConnection(URL, info);
本文转自zylhsy 51CTO博客,原文链接:http://blog.51cto.com/yunlongzheng/562439,如需转载请自行联系原作者