記一次springboot配置事務@transactional失效的事故
阿新 • • 發佈：2018-08-09
2.6 ext abs oca filter llb const cached processor
問題：
有兩張表，分別是user（用戶信息表），user_role（用戶角色信息表），添加一個用戶的同時會在user_info表中插入該用戶的用戶角色信息記錄。在添加一個用戶信息時，由於用戶信息重復，導致主鍵沖突，user表插入用戶信息失敗，此時按照正常邏輯,user_info表也會插入不成功，事務會回滾。但是結果是user_info中的記錄插入成功了。
項目啟動後的日誌如下：
2018-08-08 17:17:41.496 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10008ms elapsed since last write check.2018-08-08 17:17:41.496 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:41.655 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10010ms elapsed since last write check. 2018-08-08 17:17:41.655 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:41.710 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10003ms elapsed since last write check. 2018-08-08 17:17:41.710 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:41.710 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10003ms elapsed since last write check.2018-08-08 17:17:41.710 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:41.710 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10003ms elapsed since last write check. 2018-08-08 17:17:41.710 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:41.710 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10003ms elapsed since last write check. 2018-08-08 17:17:41.710 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:51.497 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10001ms elapsed since last write check. 2018-08-08 17:17:51.498 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:51.664 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10009ms elapsed since last write check. 2018-08-08 17:17:51.664 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:51.726 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10016ms elapsed since last write check. 2018-08-08 17:17:51.726 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:51.726 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10016ms elapsed since last write check. 2018-08-08 17:17:51.726 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10016ms elapsed since last write check. 2018-08-08 17:17:51.726 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:51.726 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:51.726 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10016ms elapsed since last write check. 2018-08-08 17:17:51.726 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:17:52.591 DEBUG 7692 --- [8080-Acceptor-0] o.apache.tomcat.util.threads.LimitLatch : Counting up[http-nio-8080-Acceptor-0] latch=1 2018-08-08 17:17:52.592 DEBUG 7692 --- [8080-Acceptor-0] o.apache.tomcat.util.threads.LimitLatch : Counting up[http-nio-8080-Acceptor-0] latch=2 2018-08-08 17:17:52.595 DEBUG 7692 --- [nio-8080-exec-3] o.a.coyote.http11.Http11InputBuffer : Received [GET /user/insertUser HTTP/1.1 Host: localhost:8080 Connection: keep-alive Cache-Control: max-age=0 Upgrade-Insecure-Requests: 1 User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.87 Safari/537.36 Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8 Accept-Encoding: gzip, deflate, br Accept-Language: zh-CN,zh;q=0.9 ] 2018-08-08 17:17:52.597 DEBUG 7692 --- [nio-8080-exec-3] o.a.c.authenticator.AuthenticatorBase : Security checking request GET /user/insertUser 2018-08-08 17:17:52.597 DEBUG 7692 --- [nio-8080-exec-3] org.apache.catalina.realm.RealmBase : No applicable constraints defined 2018-08-08 17:17:52.597 DEBUG 7692 --- [nio-8080-exec-3] o.a.c.authenticator.AuthenticatorBase : Not subject to any constraint 2018-08-08 17:17:52.598 DEBUG 7692 --- [nio-8080-exec-3] org.apache.tomcat.util.http.Parameters : Set encoding to UTF-8 2018-08-08 17:17:52.598 DEBUG 7692 --- [nio-8080-exec-3] o.s.b.w.f.OrderedRequestContextFilter : Bound request context to thread: org.apache.catalina.connector.RequestFacade@6fcff028 2018-08-08 17:17:52.598 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : DispatcherServlet with name ‘dispatcherServlet‘ processing GET request for [/user/insertUser] 2018-08-08 17:17:52.598 DEBUG 7692 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /user/insertUser 2018-08-08 17:17:52.598 DEBUG 7692 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Returning handler method [public java.lang.String org.spring.web.controller.UserController.insertUser()] 2018-08-08 17:17:52.599 DEBUG 7692 --- [nio-8080-exec-3] o.s.b.f.s.DefaultListableBeanFactory : Returning cached instance of singleton bean ‘userController‘ 2018-08-08 17:17:52.599 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : Last-Modified value for [/user/insertUser] is: -1 2018-08-08 17:17:52.599 DEBUG 7692 --- [nio-8080-exec-3] o.s.j.d.DataSourceTransactionManager : Creating new transaction with name [org.spring.web.controller.UserController.insertUser]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; ‘‘ 2018-08-08 17:17:52.601 DEBUG 7692 --- [nio-8080-exec-3] o.s.j.d.DataSourceTransactionManager : Acquired Connection [ProxyConnection[PooledConnection[com.mysql.jdbc.JDBC4Connection@17ff0053]]] for JDBC transaction 2018-08-08 17:17:52.601 DEBUG 7692 --- [nio-8080-exec-3] o.s.j.d.DataSourceTransactionManager : Switching JDBC Connection [ProxyConnection[PooledConnection[com.mysql.jdbc.JDBC4Connection@17ff0053]]] to manual commit 2018-08-08 17:17:52.601 DEBUG 7692 --- [nio-8080-exec-3] org.mybatis.spring.SqlSessionUtils : Creating a new SqlSession 2018-08-08 17:17:52.601 DEBUG 7692 --- [nio-8080-exec-3] org.mybatis.spring.SqlSessionUtils : Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2b29164f] 2018-08-08 17:17:52.602 DEBUG 7692 --- [nio-8080-exec-3] o.m.s.t.SpringManagedTransaction : JDBC Connection [ProxyConnection[PooledConnection[com.mysql.jdbc.JDBC4Connection@17ff0053]]] will be managed by Spring 2018-08-08 17:17:52.602 DEBUG 7692 --- [nio-8080-exec-3] o.s.w.m.UserRoleMapper.insertUserRole : ==> Preparing: insert into user_role ( user_id, role_id, descInfo ) values ( ?, ?, ? ) 2018-08-08 17:17:52.602 DEBUG 7692 --- [nio-8080-exec-3] o.s.w.m.UserRoleMapper.insertUserRole : ==> Parameters: 111(String), 999(String), uuuu(String) 2018-08-08 17:17:52.603 DEBUG 7692 --- [nio-8080-exec-3] o.s.w.m.UserRoleMapper.insertUserRole : <== Updates: 1 2018-08-08 17:17:52.603 DEBUG 7692 --- [nio-8080-exec-3] org.mybatis.spring.SqlSessionUtils : Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2b29164f] 2018-08-08 17:17:52.603 DEBUG 7692 --- [nio-8080-exec-3] org.mybatis.spring.SqlSessionUtils : Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2b29164f] from current transaction 2018-08-08 17:17:52.604 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.mapper.UserMapper.insertUser : ==> Preparing: insert into user ( id, age, user_name, password ) values ( ?, ?, ?, ? ) 2018-08-08 17:17:52.604 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.mapper.UserMapper.insertUser : ==> Parameters: 11(Integer), 11(Integer), nihao(String), password(String) 2018-08-08 17:17:52.662 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.mapper.UserMapper.insertUser : <== Updates: 1 2018-08-08 17:17:52.662 DEBUG 7692 --- [nio-8080-exec-3] org.mybatis.spring.SqlSessionUtils : Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2b29164f] 2018-08-08 17:17:52.662 DEBUG 7692 --- [nio-8080-exec-3] org.mybatis.spring.SqlSessionUtils : Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2b29164f] 2018-08-08 17:17:52.662 DEBUG 7692 --- [nio-8080-exec-3] org.mybatis.spring.SqlSessionUtils : Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2b29164f] 2018-08-08 17:17:52.662 DEBUG 7692 --- [nio-8080-exec-3] o.s.j.d.DataSourceTransactionManager : Initiating transaction rollback 2018-08-08 17:17:52.663 DEBUG 7692 --- [nio-8080-exec-3] o.s.j.d.DataSourceTransactionManager : Rolling back JDBC transaction on Connection [ProxyConnection[PooledConnection[com.mysql.jdbc.JDBC4Connection@17ff0053]]] 2018-08-08 17:17:52.702 DEBUG 7692 --- [nio-8080-exec-3] o.s.j.d.DataSourceTransactionManager : Releasing JDBC Connection [ProxyConnection[PooledConnection[com.mysql.jdbc.JDBC4Connection@17ff0053]]] after transaction 2018-08-08 17:17:52.702 DEBUG 7692 --- [nio-8080-exec-3] o.s.jdbc.datasource.DataSourceUtils : Returning JDBC Connection to DataSource 2018-08-08 17:17:52.702 DEBUG 7692 --- [nio-8080-exec-3] .m.m.a.ExceptionHandlerExceptionResolver : Resolving exception from handler [public java.lang.String org.spring.web.controller.UserController.insertUser()]: java.lang.RuntimeException: 拋異常 2018-08-08 17:17:52.702 DEBUG 7692 --- [nio-8080-exec-3] .w.s.m.a.ResponseStatusExceptionResolver : Resolving exception from handler [public java.lang.String org.spring.web.controller.UserController.insertUser()]: java.lang.RuntimeException: 拋異常 2018-08-08 17:17:52.702 DEBUG 7692 --- [nio-8080-exec-3] .w.s.m.s.DefaultHandlerExceptionResolver : Resolving exception from handler [public java.lang.String org.spring.web.controller.UserController.insertUser()]: java.lang.RuntimeException: 拋異常 2018-08-08 17:17:52.703 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : Could not complete request java.lang.RuntimeException: 拋異常 at org.spring.web.controller.UserController.insertUser(UserController.java:81) ~[classes/:na] at org.spring.web.controller.UserController$$FastClassBySpringCGLIB$$8630d08.invoke(<generated>) ~[classes/:na] at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720) ~[spring-aop-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) ~[spring-tx-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655) ~[spring-aop-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.spring.web.controller.UserController$$EnhancerBySpringCGLIB$$c0911a9d.insertUser(<generated>) ~[classes/:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_121] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_121] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_121] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_121] at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:114) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:963) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) [spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861) [spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:622) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) [spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) [tomcat-embed-websocket-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) [spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:89) [spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77) [spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) [spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:108) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:349) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:784) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:802) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1410) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-8.5.5.jar:8.5.5] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_121] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_121] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-8.5.5.jar:8.5.5] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_121] 2018-08-08 17:17:52.704 DEBUG 7692 --- [nio-8080-exec-3] o.s.b.w.f.OrderedRequestContextFilter : Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@6fcff028 2018-08-08 17:17:52.705 ERROR 7692 --- [nio-8080-exec-3] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.RuntimeException: 拋異常] with root cause java.lang.RuntimeException: 拋異常 at org.spring.web.controller.UserController.insertUser(UserController.java:81) ~[classes/:na] at org.spring.web.controller.UserController$$FastClassBySpringCGLIB$$8630d08.invoke(<generated>) ~[classes/:na] at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720) ~[spring-aop-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) ~[spring-tx-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655) ~[spring-aop-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.spring.web.controller.UserController$$EnhancerBySpringCGLIB$$c0911a9d.insertUser(<generated>) ~[classes/:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_121] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_121] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_121] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_121] at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:114) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:963) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:622) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) ~[spring-webmvc-4.3.3.RELEASE.jar:4.3.3.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-embed-websocket-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:89) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.3.RELEASE.jar:4.3.3.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) ~[tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:108) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:349) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:784) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:802) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1410) [tomcat-embed-core-8.5.5.jar:8.5.5] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-8.5.5.jar:8.5.5] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_121] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_121] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-8.5.5.jar:8.5.5] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_121] 2018-08-08 17:17:52.706 DEBUG 7692 --- [nio-8080-exec-3] o.a.c.c.C.[Tomcat].[localhost] : Processing ErrorPage[errorCode=0, location=/error] 2018-08-08 17:17:52.707 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : DispatcherServlet with name ‘dispatcherServlet‘ processing GET request for [/error] 2018-08-08 17:17:52.707 DEBUG 7692 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /error 2018-08-08 17:17:52.707 DEBUG 7692 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Returning handler method [public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)] 2018-08-08 17:17:52.708 DEBUG 7692 --- [nio-8080-exec-3] o.s.b.f.s.DefaultListableBeanFactory : Returning cached instance of singleton bean ‘basicErrorController‘ 2018-08-08 17:17:52.708 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : Last-Modified value for [/error] is: -1 2018-08-08 17:17:52.708 DEBUG 7692 --- [nio-8080-exec-3] o.s.c.e.PropertySourcesPropertyResolver : Found key ‘spring.template.provider.cache‘ in [refresh] with type [String] 2018-08-08 17:17:52.712 DEBUG 7692 --- [nio-8080-exec-3] o.s.c.e.PropertySourcesPropertyResolver : Found key ‘spring.template.provider.cache‘ in [refresh] with type [String] 2018-08-08 17:17:52.715 DEBUG 7692 --- [nio-8080-exec-3] o.s.w.s.v.ContentNegotiatingViewResolver : Requested media types are [text/html, text/html;q=0.8] based on Accept header types and producible media types [text/html]) 2018-08-08 17:17:52.715 DEBUG 7692 --- [nio-8080-exec-3] o.s.b.f.s.DefaultListableBeanFactory : Returning cached instance of singleton bean ‘error‘ 2018-08-08 17:17:52.715 DEBUG 7692 --- [nio-8080-exec-3] o.s.w.s.v.ContentNegotiatingViewResolver : Returning [org.springframework.boot.autoconfigure.web.ErrorMvcAutoConfiguration$SpelView@2f2af303] based on requested media type ‘text/html‘ 2018-08-08 17:17:52.715 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : Rendering view [org.springframework.boot.autoconfigure.web.ErrorMvcAutoConfiguration$SpelView@2f2af303] in DispatcherServlet with name ‘dispatcherServlet‘ 2018-08-08 17:17:52.715 DEBUG 7692 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : Successfully completed request 2018-08-08 17:17:52.716 DEBUG 7692 --- [nio-8080-exec-3] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Disabling the response for futher output 2018-08-08 17:17:52.719 DEBUG 7692 --- [nio-8080-exec-3] o.apache.coyote.http11.Http11Processor : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2e76b354:org.apache.tomcat.util.net.NioChannel@5d4092f:java.nio.channels.SocketChannel[connected local=/0:0:0:0:0:0:0:1:8080 remote=/0:0:0:0:0:0:0:1:53329]], Status in: [OPEN_READ], State out: [CLOSED] 2018-08-08 17:17:52.719 DEBUG 7692 --- [nio-8080-exec-3] o.apache.tomcat.util.threads.LimitLatch : Counting down[http-nio-8080-exec-3] latch=2 2018-08-08 17:18:01.307 DEBUG 7692 --- [ ReadCheckTimer] o.a.a.t.AbstractInactivityMonitor : 30003ms elapsed since last read check. 2018-08-08 17:18:01.310 DEBUG 7692 --- [ ReadCheckTimer] o.a.a.t.AbstractInactivityMonitor : 30002ms elapsed since last read check. 2018-08-08 17:18:01.310 DEBUG 7692 --- [ ReadCheckTimer] o.a.a.t.AbstractInactivityMonitor : 30002ms elapsed since last read check. 2018-08-08 17:18:01.328 DEBUG 7692 --- [ ReadCheckTimer] o.a.a.t.AbstractInactivityMonitor : 30001ms elapsed since last read check. 2018-08-08 17:18:01.328 DEBUG 7692 --- [ ReadCheckTimer] o.a.a.t.AbstractInactivityMonitor : 30001ms elapsed since last read check. 2018-08-08 17:18:01.328 DEBUG 7692 --- [ ReadCheckTimer] o.a.a.t.AbstractInactivityMonitor : 30001ms elapsed since last read check. 2018-08-08 17:18:01.503 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10006ms elapsed since last write check. 2018-08-08 17:18:01.503 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:18:01.675 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10011ms elapsed since last write check. 2018-08-08 17:18:01.676 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:18:01.742 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10016ms elapsed since last write check. 2018-08-08 17:18:01.742 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:18:01.742 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10016ms elapsed since last write check. 2018-08-08 17:18:01.742 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10016ms elapsed since last write check. 2018-08-08 17:18:01.742 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:18:01.742 DEBUG 7692 --- [WriteCheckTimer] o.a.a.t.AbstractInactivityMonitor : WriteChecker: 10016ms elapsed since last write check. 2018-08-08 17:18:01.742 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616] 2018-08-08 17:18:01.742 DEBUG 7692 --- [yMonitor Worker] o.a.a.t.AbstractInactivityMonitor : Running WriteCheck[tcp://127.0.0.1:61616]
日誌中可以看到是有事務回滾的。
解決方法：
創建user_info表的語句如下：
CREATE TABLE `user_role` ( `user_id` varchar(20) NOT NULL, `role_id` varchar(20) NOT NULL, `descInfo` varchar(50) DEFAULT ‘描述信息‘, UNIQUE KEY `user_role` (`user_id`(10),`role_id`) ) ENGINE=MyISAM DEFAULT CHARSET=utf8
由於mysql 中 myisam不支持事務，修改該表的engine為innodb
記一次springboot配置事務@transactional失效的事故