起因
9月第二周,9.14~9.18日,周计划是辅导项目组同事完成一个特性的优化,消除可能存在的性能问题。
这个特性说起来很简单,用户在页面上操作,选定一些字段,导出生成一个Excel格式的模板,然后用户填充页面导出的模板,最终在页面上导入模板。过程并不复杂,在执行模板导入时出现了异常。测试人员的反馈很有意思,模板里有1000条数据时,费时120秒;模板里有2000条及以上的数据时,120秒之后页面直接提示用户导入失败,后台报出异常;3000条数据的场景没有验证。
测试人员前段时间因家事请假比较多,前述的问题是在深夜赶工时发现的,由于问题必现,而他自身待完成的工作比较多,所以没有停下来收集日志,而是选择了继续执行其它项目的验证,因此第二天发出的报告中没有附上问题出现时的日志。
原始问题的分析
1000条数据时可以正常导入,说明功能没有问题;此前多轮的功能验证也可以证明该特性实现是正确的;
1000条数据导入时花费120秒,从结果看远远超出了预期,但在进一步分析之前,无法判定可否优化,需要进一步分析;
2000条数据导入时花费时间长,并且导入失败,后台报错,说明导入时的失败和数据量有关系,需要进一步分析;
2000条数据导入时,后台有报错,既然有报错并且问题必现,那么使用相同的数据量重试即可提取到相关的日志;
从前述分析看,问题还不太复杂,于是直接安排开发人员上手分析。
中午下班前,开发人员找我聊处理进展,基本和我的预期相近:
祭出jstack,提取导入操作过程中的栈,对照代码划分了时间花费的分布,整理得到了一些优化点;
准备2000条数据执行导入操作,顺利得提取到了异常日志,原来是“1390 Prepared statement contains too many placeholders”,和MySQL相关;
Java应用的优化或者说改进,我倒是不担心,但涉及到MySQL相关的问题就不好讲了。
异常日志中的惊喜
从异常日志中提到了线索,“Prepared statement contains too many placeholders”,这是一个意外的惊喜。
MySQL官网的资料相当简单,从中得不到任何有意义的说明。
Error: 1390 SQLSTATE: HY000 (ER_PS_MANY_PARAM)
Message: Prepared statement contains too many placeholders
但stackoverflow上的热心网友对于这个现象有很深刻的见解,看来受这个问题困扰的人不只我一个。
从网友的答复吕得到的重要信息是,MySQL的prepared statement只能支持至多65535个占位变量,但原因不详。
具体到当前项目组遇到的问题,我们在使用MySQL JDBC驱动时,为了提升数据插入的效率,启用了rewriteBatchedStatements特性,在批量插入数据时,MySQL的JDBC驱动会将单条的插入语句合并为一条多值的插入语句;而我们导入的数据规模,一条记录有60列,当导入数据时为1000条记录时,SQL中占位符的数目恰好小于65535;当导入2000条记录时,SQL中点位符的数目已超过65535,语句执行时必然报错。
了解了引发问题的原因,修复的方法就明确了,将待入库的数据按照1000拆分为多批,在多个事务中完成插入操作,规避MySQL对占位符的限制。
这个解决方法不完美,破坏了预期的数据事务性,但暂时没有想到更好的方法。
参考
http://dev.mysql.com/doc/refman/5.7/en/error-messages-server.html
http://stackoverflow.com/questions/18100782/import-of-50k-records-in-mysql-gives-general-error-1390-prepared-statement-con