下午自測代碼,在這個update上卡了一個半小時,大大的降低了開發的生產力,把排查過程發出來,好的士兵不會掉進同一個陷阱。先把異常堆棧打出來。
2016-03-28 17:23:38.420 main DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory:463] - Finished creating instance of bean 'Sybase' 2016-03-28 17:23:38.420 main INFO [org.springframework.jdbc.support.SQLErrorCodesFactory:126] - SQLErrorCodes loaded: [DB2, Derby, H2, HSQL, Informix, MS-SQL, MySQL, Oracle, PostgreSQL, Sybase] 2016-03-28 17:23:38.420 main DEBUG [org.springframework.jdbc.support.SQLErrorCodesFactory:199] - Looking up default SQLErrorCodes for DataSource [com.jd.im.data.dataresource.JdDataSourceDbcp@14021a9] 2016-03-28 17:23:38.423 main DEBUG [org.springframework.jdbc.support.SQLErrorCodesFactory:217] - Database product name cached for DataSource [com.jd.im.data.dataresource.JdDataSourceDbcp@14021a9]: name is 'MySQL' 2016-03-28 17:23:38.423 main DEBUG [org.springframework.jdbc.support.SQLErrorCodesFactory:175] - SQL error codes for 'MySQL' found 2016-03-28 17:23:38.423 main DEBUG [org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator:399] - Translating SQLException with SQL state '42000', error code '1064', message [ --- The error occurred while applying a parameter map. --- Check the mall.org.updateById-InlineParameterMap. --- Check the statement (update failed). --- Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'WHERE id = 12' at line 1]; SQL was [] for task [SqlMapClient operation] 2016-03-28 17:23:38.424 main ERROR [com.jd.dd.mall.service.waiter.impl.OrgService?Impl:97] - IM data access exception com.jd.im.data.exception.IMDataAccessException: IM data access exception at com.jd.im.data.dataresource.IMSqlMapClientTemplateForMultDs.handleUserException(IMSqlMapClientTemplateForMultDs.java:280) at com.jd.im.data.dataresource.IMSqlMapClientTemplateForMultDs.update(IMSqlMapClientTemplateForMultDs.java:160) at com.jd.dd.mall.service.waiter.impl.OrgService?Impl.updateById(OrgService?Impl.java:106) at com.jd.dd.mall.service.waiter.impl.OrgService?Impl.add(OrgService?Impl.java:92) at com.jd.dd.mall.web.controller.waiter.OrgManageController.addOrg(OrgManageController.java:85) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:219) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:746) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:687) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:915) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:822) at javax.servlet.http.HttpServlet.service(HttpServlet.java:727) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:796) at org.springframework.test.web.servlet.TestDispatcherServlet.service(TestDispatcherServlet.java:66) at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) at org.springframework.mock.web.MockFilterChain$ServletFilterProxy.doFilter(MockFilterChain.java:168) at org.springframework.mock.web.MockFilterChain.doFilter(MockFilterChain.java:136) at org.springframework.test.web.servlet.MockMvc.perform(MockMvc.java:134) at com.jd.service.waiter.OrgControllerTest.add(OrgControllerTest.java:53) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:74) at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:83) at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:72) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:231) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:88) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:71) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:174) at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50) at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:675) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192) Caused by: org.springframework.jdbc.BadSqlGrammarException: SqlMapClient operation; bad SQL grammar []; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException: --- The error occurred while applying a parameter map. --- Check the mall.org.updateById-InlineParameterMap. --- Check the statement (update failed). --- Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'WHERE id = 12' at line 1 at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:233) at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:206) at org.springframework.orm.ibatis.SqlMapClientTemplate.update(SqlMapClientTemplate.java:381) at com.jd.im.data.dataresource.IMSqlMapClientTemplateForMultDs.update(IMSqlMapClientTemplateForMultDs.java:134) ... 54 more Caused by: com.ibatis.common.jdbc.exception.NestedSQLException: --- The error occurred while applying a parameter map. --- Check the mall.org.updateById-InlineParameterMap. --- Check the statement (update failed). --- Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'WHERE id = 12' at line 1 at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeUpdate(MappedStatement.java:107) at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.update(SqlMapExecutorDelegate.java:457) at com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.update(SqlMapSessionImpl.java:90) at org.springframework.orm.ibatis.SqlMapClientTemplate$9.doInSqlMapClient(SqlMapClientTemplate.java:383) at org.springframework.orm.ibatis.SqlMapClientTemplate$9.doInSqlMapClient(SqlMapClientTemplate.java:381) at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:203) ... 56 more
像這種堆棧沒有明確指明原因的sql問題,排查問題肯定是根據error code去查。百度了下這個1064 error code。說是表的列名跟Mysql的關鍵字重疊了。OK,我把這個sql貼近mysql客戶端的查詢界面,發現name字段變成了關鍵字的顏色。我以為找到問題了,於是把name前後加反引號。再跑下單元測試,依然報1064錯誤。UPDATE org SET name = #name:VARCHAR#, tree_level = #tree_level#, yn = #yn#, route = #route:VARCHAR#, `version` = `version` + 1,editor = #editor:VARCHAR# WHERE id = #id#
沒轍,只能把ibatis的執行的sql打出來,放進mysql客戶端看看。OK,log4j加日志,把ibatis的執行sql打出來。再跑一遍單元測試,sql並沒有打出來。
有種叫天天不應叫地地不靈的沮喪感!
沒辦法,只能肉眼看sql。如果editor字段為null,那麼where前面就多個多余的逗號了。調整下sql。
在跑下單元測試,sql成功的執行。mysql的error code一點都不靠譜!明明是sql語法有問題,卻報1064的code。UPDATE org SET id = #id# , `name` = #name:VARCHAR#, tree_level = #tree_level#, yn = #yn#, route = #route:VARCHAR#, editor = #editor:VARCHAR# , `version` = `version` + 1 WHERE id = #id#
把name和version字段上的反引號去掉,sql依然可以正常的執行。吐槽!