Mybatis Error attempting to get column xx. Bad format for number '2018-09-18' in column 20（数据类型转换错误）

本文主要分享下类似问题的排查过程。

执行查询时报错，错误日志摘要：

org.springframework.dao.TransientDataAccessResourceException: 
Error attempting to get column 'create_time' from result set. Cause: java.sql.SQLException: Bad format for number '2018-09-18 19:29:02.0' in column 20.

日志提醒的很明显，列'create_time'取值失败，原因是格式不对、不是数字。
那么问题来了：我的MySQL表中，create_time是datetime类型，讲道理应该转换为java.util.Date对象，怎么会转数字呢？

排查

完整日志如下：

Caused by: java.sql.SQLException: Bad format for number '2018-09-18 19:29:02.0' in column 20.at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:965)at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:898)at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:887)at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:861)at com.mysql.jdbc.ResultSetImpl.getDoubleInternal(ResultSetImpl.java:2333)at com.mysql.jdbc.ResultSetImpl.getDoubleInternal(ResultSetImpl.java:2273)at com.mysql.jdbc.ResultSetImpl.getDouble(ResultSetImpl.java:2241)at com.mysql.jdbc.ResultSetImpl.getDouble(ResultSetImpl.java:2253)at org.apache.commons.dbcp2.DelegatingResultSet.getDouble(DelegatingResultSet.java:295)at org.apache.commons.dbcp2.DelegatingResultSet.getDouble(DelegatingResultSet.java:295)at org.dommons.db.jdbc.EssentialResultSet.getDouble(EssentialResultSet.java:216)at org.dommons.db.jdbc.EssentialResultSet.getDouble(EssentialResultSet.java:216)at org.apache.ibatis.type.DoubleTypeHandler.getNullableResult(DoubleTypeHandler.java:37)at org.apache.ibatis.type.DoubleTypeHandler.getNullableResult(DoubleTypeHandler.java:26)at org.apache.ibatis.type.BaseTypeHandler.getResult(BaseTypeHandler.java:66)at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.createRowKeyForMappedProperties(DefaultResultSetHandler.java:1073)at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.createRowKey(DefaultResultSetHandler.java:1030)at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.applyNestedResultMappings(DefaultResultSetHandler.java:957)at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.getRowValue(DefaultResultSetHandler.java:918)at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.handleRowValuesForNestedResultMap(DefaultResultSetHandler.java:881)at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.handleRowValues(DefaultResultSetHandler.java:328)at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.handleResultSet(DefaultResultSetHandler.java:303)at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.handleResultSets(DefaultResultSetHandler.java:196)at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:64)at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79)at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:63)at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:326)at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:83)at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(Method.java:498)at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:433)

通过堆栈可以看到，Mybatis使用了DoubleTypeHandler转换了我这个create_time日期数据，用了这个Handler报错是Bad format for number就可以理解了。

那么问题变成为什么Mybatis选择了这个Handler。

有个小插曲，最开始没用日志，而是主观的去判断了下问题想走走捷径：

1. 因为这个值刚好在association中定义的，我怀疑这个标签有问题，会选择错类型转换器。还去除了association重试了下，果然没有错误了。于是莫名的开始嗨，感觉发现了惊天大咪咪。
2. 有了1的判断，尝试在xml中显式配置jdbcType为DATE(常见的jdbcType)，重试时报错仍然存在。这个时候网上查了查没有类似资料，线索断了。只能回到日志排查源码了。

最终证明我是浪费了时间。 遇到问题还是不能太主观，有明显的日志了，还是按图索骥比较靠谱。

开启debug，F5按调用一层一层跟进去，找到异常拦截和处理的代码：org.apache.ibatis.type.BaseTypeHandler<T>.getResult(ResultSet rs, String columnName)。

看到这段代码，可以注意到两个关键点：

1. columnName是一个入参，也就是解析结果集可能是遍历时传入的，日志里明确提示了是create_time，应该没问题；

   Error attempting to get column create_time from result set.

2. 回想最开始我们看到的日志，Cause后面的部分（Bad format for number ‘2018-09-18’ in column 20）是从接收的异常中拿到的。那么接下来应该进入到异常抛出的地方。
3. 继续调试，终于找到了异常抛出类，并且发现column 20是通过findColumn获取到的； 查看sql结果集的列，发现列名、序号是对的上的。
   

在这里我突然灵光一闪，幡然醒悟了一个思维误区：

日志中提示的一直是column create_time、column 20，但并没有说是在转换ResultMap的create_time属性。也就是说理论上，ResultSet的create_time属性值，可能正被提取解析成ResultMap的任意属性。要验证这一点，直接去Mybatis的ResultMap配置中，查看是否有多个属性的column都配置了create_time。

事实证明确实如此，有个金额属性，column映射到了create_time，所以转换报错了。

总结

这个问题有几个关键点，如果能早些注意、或者有知识储备，解决问题会很快：

1. column 20： com.mysql.jdbc.ResultSetImpl.findColumn找到的列索引。注意，是列索引，不是ResultMap中属性的顺序号，所以不要看到这个属性名，就去看这个属性类型转换有什么问题。而应该去查一查执行的sql结果集，第20列是什么内容，ResultMap中是否有多个字段的column错误配置了该列、导致类型不匹配。
2. Mybatis选择哪个TypeHandler，默认是根据ResultMap中property的类型来的（当然还可以显示指定）。所以如果发现TypeHandler和预想的不一样，应该意识到问题出在某个property与column不匹配。

又是一个巨大的乌龙，一星期就遇到了两次，而且一次比一次离(di)奇(ji)，这次已经超越MySQL ERROR 16 (42000):FUNCTION sum does not exist. Check the ‘Function Name Parsing and Resolution’，成为2019悲惨事件top1。感觉今年剩下的四个月很难熬。

解决问题过程中发现的其他类似事件，也比较有价值：https://blog.csdn.net/m0_43452671/article/details/89315225、https://blog.csdn.net/gugou123/article/details/80920431、

因为错怪了association，特意找了两篇文章再学习了下：https://www.cnblogs.com/yuan951/p/7594176.html、https://www.cnblogs.com/duanxz/p/3830509.html