mybatis的坑——不报错,就是不能committing,数据存不进数据库

本文通过一个关于空指针异常的案例,强调了在MyBatis中mapper文件的property属性名与接收类属性名保持一致的重要性。作者经历了一周的排查,最终发现错误源于属性名的不匹配,提醒开发者们注意代码细节,避免类似问题。

测试的时候会报空指针异常,在项目跑的时候会停止执行程序,不会出现异常。

经过一星期的排查与测试,最终找到错误,把mapper文件的映射属性名写错了。

property属性名要与接收类的属性名保持一致。

这是一个惨痛的教训,特此记住,引以为戒。

 

转载于:https://www.cnblogs.com/yang-xiansen/p/10527014.html

2025-10-04 18:26:17,795 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:17,795 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@ba474ac] 2025-10-04 18:26:18,188 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@ba474ac] 2025-10-04 18:26:18,188 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5bb79966] 2025-10-04 18:26:18,188 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@ba474ac] 2025-10-04 18:26:18,188 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@5729a452] will be managed by Spring 2025-10-04 18:26:18,469 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:18,469 DEBUG rrc.mybatis.mapper.UserMapper.findUserByUserName - - ==> Preparing: select T.USER_ID userId, T.USER_NAME userName, T.USER_CN_NAME userCnName, T.USER_DESC userDesc, T.USER_SHIFT userShift, T.USER_POST userPost, T.USER_PHONE userPhone, T.USER_PASSWORD userPassword, T.USER_PASSWORD_SALT userPasswordSalt, T.USER_CREAT_DATE userCreatDate, T.USER_UPDATE_DATE userUpdateDate, T.USER_EMAIL_ADDR userEmailAddr, T.USER_ENABLED userEnabled, T.USER_NODE_ROLE userNodeRole, T.USER_FAB_SITE userFabSite from TB_RRC_RBAC_USER T where T.USER_NAME=? 2025-10-04 18:26:18,469 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1efb3456] 2025-10-04 18:26:18,784 DEBUG rrc.mybatis.mapper.UserMapper.findUserByUserName - - ==> Parameters: JE02787(String) 2025-10-04 18:26:18,784 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@2630bc2b] will be managed by Spring 2025-10-04 18:26:19,085 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findUserLinkPrivList - - > Preparing: SELECT T4.PRIV_ID privId, T4.PRIV_NAME privName, T4.PRIV_PARENT_ID privParentId, T4.PRIV_ORDERS privOrders, T4.PRIV_TYPE privType, T4.PRIV_ICON privIcon, T4.PRIV_CSS privCss, T4.PRIV_URL privUrl, T4.PRIV_CREAT_DATE privCreatDate, T4.PRIV_UPDATE_DATE privUpdateDate, T4.PRIV_ENABLED privEnabled FROM TB_RRC_RBAC_PRIV T4, (SELECT DISTINCT PRIV_ID FROM TB_RRC_RBAC_ROLE_PRIV T3 WHERE T3.ROLE_ID IN (SELECT DISTINCT T2.ROLE_ID FROM TB_RRC_RBAC_USER_ROLE T2 WHERE T2.USER_ID =?)) TT WHERE T4.PRIV_TYPE = ‘LINK’ AND T4.PRIV_ID = TT.PRIV_ID AND T4.PRIV_ENABLED = ‘1’ 2025-10-04 18:26:19,085 DEBUG rrc.mybatis.mapper.UserMapper.findUserByUserName - - < Total: 1 2025-10-04 18:26:19,088 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findUserLinkPrivList - - > Parameters: 1324(String) 2025-10-04 18:26:19,441 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5bb79966] 2025-10-04 18:26:19,441 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5bb79966] 2025-10-04 18:26:19,928 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5bb79966] 2025-10-04 18:26:19,928 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findUserLinkPrivList - - < Total: 5 2025-10-04 18:26:19,928 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5bb79966] 2025-10-04 18:26:19,928 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1efb3456] 2025-10-04 18:26:20,903 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:20,903 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1efb3456] 2025-10-04 18:26:21,341 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5987214c] 2025-10-04 18:26:21,341 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1efb3456] 2025-10-04 18:26:21,764 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@5729a452] will be managed by Spring 2025-10-04 18:26:21,764 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1efb3456] 2025-10-04 18:26:22,094 DEBUG rrc.mybatis.mapper.DictionaryMapper.selectDictionaryByFieldTypeAndFabSite - - ==> Preparing: SELECT ID, FIELD_TYPE, FIELD_DESC, FIELD_KEY, FIELD_VALUE, FIELD_ORDER, FIELD_FAB_SITE FROM TB_RRC_FIELD_DICTIONARY WHERE FIELD_TYPE = ? AND FIELD_FAB_SITE = ? ORDER BY FIELD_ORDER 2025-10-04 18:26:22,536 DEBUG rrc.mybatis.mapper.DictionaryMapper.selectDictionaryByFieldTypeAndFabSite - - > Parameters: AREA(String), J2A(String) 2025-10-04 18:26:22,536 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:22,972 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@24dff6a7] 2025-10-04 18:26:24,203 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@2630bc2b] will be managed by Spring 2025-10-04 18:26:24,203 DEBUG rrc.mybatis.mapper.DictionaryMapper.selectDictionaryByFieldTypeAndFabSite - - < Total: 67 2025-10-04 18:26:24,533 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findSystemAvailLinkPrivList - - ==> Preparing: SELECT T.PRIV_ID privId, T.PRIV_NAME privName, T.PRIV_PARENT_ID privParentId, T.PRIV_ORDERS privOrders, T.PRIV_TYPE privType, T.PRIV_ICON privIcon, T.PRIV_CSS privCss, T.PRIV_URL privUrl, T.PRIV_CREAT_DATE privCreatDate, T.PRIV_UPDATE_DATE privUpdateDate, T.PRIV_ENABLED privEnabled FROM TB_RRC_RBAC_PRIV T WHERE T.PRIV_TYPE=‘LINK’ AND T.PRIV_ENABLED=‘1’ 2025-10-04 18:26:24,533 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5987214c] 2025-10-04 18:26:24,892 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5987214c] 2025-10-04 18:26:24,892 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findSystemAvailLinkPrivList - - > Parameters: 2025-10-04 18:26:25,364 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5987214c] 2025-10-04 18:26:25,803 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5987214c] 2025-10-04 18:26:25,803 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findSystemAvailLinkPrivList - - < Total: 17 2025-10-04 18:26:26,291 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@24dff6a7] 2025-10-04 18:26:26,291 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:27,674 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:27,674 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@24dff6a7] 2025-10-04 18:26:28,425 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@708f411c] 2025-10-04 18:26:27,988 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@19a56137] 2025-10-04 18:26:29,159 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@7c4ad7d6] will be managed by Spring 2025-10-04 18:26:28,850 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@24dff6a7] 2025-10-04 18:26:29,871 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - ==> Preparing: select SEQ_RRC_ACCESS_HISTORY.NEXTVAL from dual 2025-10-04 18:26:29,447 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@5729a452] will be managed by Spring 2025-10-04 18:26:30,629 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - ==> Parameters: 2025-10-04 18:26:30,235 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@24dff6a7] 2025-10-04 18:26:31,101 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findUserLinkPrivList - - > Preparing: SELECT T4.PRIV_ID privId, T4.PRIV_NAME privName, T4.PRIV_PARENT_ID privParentId, T4.PRIV_ORDERS privOrders, T4.PRIV_TYPE privType, T4.PRIV_ICON privIcon, T4.PRIV_CSS privCss, T4.PRIV_URL privUrl, T4.PRIV_CREAT_DATE privCreatDate, T4.PRIV_UPDATE_DATE privUpdateDate, T4.PRIV_ENABLED privEnabled FROM TB_RRC_RBAC_PRIV T4, (SELECT DISTINCT PRIV_ID FROM TB_RRC_RBAC_ROLE_PRIV T3 WHERE T3.ROLE_ID IN (SELECT DISTINCT T2.ROLE_ID FROM TB_RRC_RBAC_USER_ROLE T2 WHERE T2.USER_ID =?)) TT WHERE T4.PRIV_TYPE = ‘LINK’ AND T4.PRIV_ID = TT.PRIV_ID AND T4.PRIV_ENABLED = ‘1’ 2025-10-04 18:26:32,758 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - < Total: 1 2025-10-04 18:26:34,888 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:33,966 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findUserLinkPrivList - - ==> Parameters: 1324(String) 2025-10-04 18:26:35,719 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@847bb2e] 2025-10-04 18:26:34,888 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - > Preparing: insert into TB_RRC_ACCESS_HISTORY (ID, ACCESS_DATE, ACCESS_URL, ACCESS_PARAMS, ACCESS_COST, ACCESS_USER, ACCESS_IP) values (?, ?, ?, ?, ?, ?, ?) 2025-10-04 18:26:37,774 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@2630bc2b] will be managed by Spring 2025-10-04 18:26:37,774 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findUserLinkPrivList - - < Total: 5 2025-10-04 18:26:37,774 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:39,323 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@19a56137] 2025-10-04 18:26:38,921 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - ==> Preparing: select SEQ_RRC_ACCESS_HISTORY.NEXTVAL from dual 2025-10-04 18:26:38,638 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - > Parameters: 41999994(BigDecimal), 2025-10-04 18:26:26.291(Timestamp), /rrc/login.html(String), &XYZ(String), 0(Long), JE02787(String), 10.105.171.11(String) 2025-10-04 18:26:40,745 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - > Parameters: 2025-10-04 18:26:40,368 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@19a56137] 2025-10-04 18:26:39,847 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3128e7ac] 2025-10-04 18:26:41,929 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - < Total: 1 2025-10-04 18:26:41,929 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@19a56137] 2025-10-04 18:26:41,487 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - < Updates: 1 2025-10-04 18:26:42,980 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - ==> Preparing: insert into TB_RRC_ACCESS_HISTORY (ID, ACCESS_DATE, ACCESS_URL, ACCESS_PARAMS, ACCESS_COST, ACCESS_USER, ACCESS_IP) values (?, ?, ?, ?, ?, ?, ?) 2025-10-04 18:26:42,980 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@19a56137] 2025-10-04 18:26:42,320 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@266f770f] will be managed by Spring 2025-10-04 18:26:43,802 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - > Parameters: 41999995(BigDecimal), 2025-10-04 18:26:33.966(Timestamp), /rrc/login.html(String), fabSite=J2A(String), 7675(Long), JE02787(String), 10.105.171.11(String) 2025-10-04 18:26:43,359 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@708f411c] 2025-10-04 18:26:45,250 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - < Updates: 1 2025-10-04 18:26:44,852 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:26:44,458 DEBUG rrc.mybatis.mapper.MailNotificationMapper.updateNotification - - ==> Preparing: UPDATE TB_RRC_MAIL_NOTIFICATION SET MAIL_SEND_FLAG = ?, MAIL_SEND_TIME = ? WHERE ID = ? 2025-10-04 18:26:46,492 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2c5cea62] 2025-10-04 18:26:45,610 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@847bb2e] 2025-10-04 18:26:45,250 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@708f411c] 2025-10-04 18:26:47,814 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@847bb2e] 2025-10-04 18:26:48,974 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@5729a452] will be managed by Spring 2025-10-04 18:26:46,492 DEBUG rrc.mybatis.mapper.MailNotificationMapper.updateNotification - - ==> Parameters: 1(Short), 2025-10-04 18:26:36.975(Timestamp), 1006803(String) 2025-10-04 18:26:49,268 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findSystemAvailLinkPrivList - - > Preparing: SELECT T.PRIV_ID privId, T.PRIV_NAME privName, T.PRIV_PARENT_ID privParentId, T.PRIV_ORDERS privOrders, T.PRIV_TYPE privType, T.PRIV_ICON privIcon, T.PRIV_CSS privCss, T.PRIV_URL privUrl, T.PRIV_CREAT_DATE privCreatDate, T.PRIV_UPDATE_DATE privUpdateDate, T.PRIV_ENABLED privEnabled FROM TB_RRC_RBAC_PRIV T WHERE T.PRIV_TYPE=‘LINK’ AND T.PRIV_ENABLED=‘1’ 2025-10-04 18:26:48,974 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@847bb2e] 2025-10-04 18:26:48,678 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@708f411c] 2025-10-04 18:26:51,308 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@847bb2e] 2025-10-04 18:26:50,866 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findSystemAvailLinkPrivList - - > Parameters: 2025-10-04 18:26:50,866 DEBUG rrc.mybatis.mapper.MailNotificationMapper.updateNotification - - < Updates: 1 2025-10-04 18:26:52,946 DEBUG com.sjsemi.rrc.interceptor.AuthorizeInterceptor - - 用户:[JE02787]访问URL:[/rrc/login.html]耗时[7675]ms 2025-10-04 18:26:52,187 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@708f411c] 2025-10-04 18:26:53,418 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3128e7ac] 2025-10-04 18:26:55,385 DEBUG com.sjsemi.rrc.interceptor.AuthorizeInterceptor - - 用户:[JE02787]访问URL:[/rrc/login.html]耗时[0]ms 2025-10-04 18:26:55,385 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3128e7ac] 2025-10-04 18:26:58,134 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3128e7ac] 2025-10-04 18:26:59,781 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3128e7ac] 2025-10-04 18:27:01,728 DEBUG rrc.mybatis.mapper.PrivilegeMapper.findSystemAvailLinkPrivList - - < Total: 17 2025-10-04 18:27:03,480 DEBUG com.sjsemi.rrc.task.MailNotificationTask - - RRC Auto Mail Send Complete 2025-10-04 18:27:03,480 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2c5cea62] 2025-10-04 18:27:06,198 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2c5cea62] 2025-10-04 18:27:06,588 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2c5cea62] 2025-10-04 18:27:07,985 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2c5cea62] 2025-10-04 18:27:11,696 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:27:12,886 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@485a233f] 2025-10-04 18:27:15,371 DEBUG org.mybatis.spring.SqlSessionUtils - - Creating a new SqlSession 2025-10-04 18:27:16,091 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@5729a452] will be managed by Spring 2025-10-04 18:27:17,014 DEBUG org.mybatis.spring.SqlSessionUtils - - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2ba02fa4] 2025-10-04 18:27:17,014 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - ==> Preparing: select SEQ_RRC_ACCESS_HISTORY.NEXTVAL from dual 2025-10-04 18:27:18,444 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - > Parameters: 2025-10-04 18:27:20,091 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert!selectKey - - < Total: 1 2025-10-04 18:27:20,091 DEBUG org.mybatis.spring.transaction.SpringManagedTransaction - - JDBC Connection [oracle.jdbc.driver.T4CConnection@266f770f] will be managed by Spring 2025-10-04 18:27:21,279 DEBUG rrc.mybatis.mapper.MailNotificationMapper.findUnSendTopRecord - - ==> Preparing: SELECT ID, MAIL_RRC_NO, MAIL_SUBJECT, MAIL_CONTENT, MAIL_FROM, MAIL_TO, MAIL_CC, MAIL_BCC, MAIL_ATTACHMENTS, MAIL_CREAT_DATE, MAIL_CREAT_USER, MAIL_SEND_FLAG, MAIL_SEND_TIME, MAIL_FAB_SITE ,ROWNUM FROM TB_RRC_MAIL_NOTIFICATION WHERE (MAIL_SEND_FLAG IS NULL OR MAIL_SEND_FLAG !=‘1’) AND ROWNUM=1 ORDER BY MAIL_CREAT_DATE ASC 2025-10-04 18:27:22,223 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - ==> Preparing: insert into TB_RRC_ACCESS_HISTORY (ID, ACCESS_DATE, ACCESS_URL, ACCESS_PARAMS, ACCESS_COST, ACCESS_USER, ACCESS_IP) values (?, ?, ?, ?, ?, ?, ?) 2025-10-04 18:27:22,725 DEBUG rrc.mybatis.mapper.MailNotificationMapper.findUnSendTopRecord - - > Parameters: 2025-10-04 18:27:24,873 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - > Parameters: 42000033(BigDecimal), 2025-10-04 18:27:10.976(Timestamp), /rrc/login.html(String), fabSite=J2A(String), 44685(Long), JE02787(String), 10.105.171.11(String) 2025-10-04 18:27:31,975 DEBUG rrc.mybatis.mapper.MailNotificationMapper.findUnSendTopRecord - - < Total: 0 2025-10-04 18:27:33,258 DEBUG rrc.mybatis.mapper.AccessHistoryMapper.insert - - < Updates: 1 2025-10-04 18:27:36,811 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2ba02fa4] 2025-10-04 18:27:38,693 DEBUG org.mybatis.spring.SqlSessionUtils - - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@485a233f] 2025-10-04 18:27:39,667 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2ba02fa4] 2025-10-04 18:27:46,064 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@485a233f] 2025-10-04 18:27:53,845 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2ba02fa4] 2025-10-04 18:27:54,327 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@485a233f] 2025-10-04 18:27:57,784 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2ba02fa4] 2025-10-04 18:27:58,359 DEBUG org.mybatis.spring.SqlSessionUtils - - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@485a233f] 2025-10-04 18:28:02,810 DEBUG com.sjsemi.rrc.interceptor.AuthorizeInterceptor - - 用户:[JE02787]访问URL:[/rrc/login.html]耗时[44685]ms 这是在之前一小段时间的日志,这个时候好像还正常,用户03427说当时在签核,签核完这一站后流到下一站,然后他准备登录02787去在下一站审核
最新发布
10-12
你提供的这段日志非常关键,它记录了**系统在崩溃前的一小段时间内正常的用户登录流程和后台任务执行情况**。通过分析这些日志,我们可以清晰地看到: - 用户 `[JE02787]` 成功完成了一次登录请求(耗时 7675ms) - 系统自动执行了邮件发送任务(`MailNotificationTask`) - 数据库操作正常完成,没有报错 - 所有 SqlSession 的创建、注册、提交、关闭都符合 Spring + MyBatis 的事务管理规范 而紧接着的后续日志中出现了 `get/close not same thread` 警告和 `connection holder is null` 错误,说明问题是在这个“看似正常”的操作之后才逐渐恶化并最终爆发的。 --- ### ✅ 回答问题:为什么之前看起来正常,后来却崩溃? #### 🔍 核心结论: > **虽然本次登录过程本身是成功的,但它可能触发了一个长期运行或异步执行的任务(如定时任务、线程池处理),该任务数据库连接使用当的问题,在后续执行中导致连接泄漏或跨线程使用,最终引发连接池耗尽、事务上下文丢失,造成系统假死。** --- ### 🧩 日志逐段解析与行为还原 #### 1. 用户 JE02787 登录全过程(成功) | 时间 | 操作 | |------|------| | `18:26:17` | 开始创建 SqlSession,入登录认证流程 | | `18:26:18` | 查询用户信息 `findUserByUserName` → 成功查到 JE02787 | | `18:26:19` | 查询用户权限 `findUserLinkPrivList` → 返回 5 条菜单权限 | | `18:26:22` | 查询字典数据 `selectDictionaryByFieldTypeAndFabSite` → 获取区域等下拉框数据 | | `18:26:24` | 查询系统可用链接权限 `findSystemAvailLinkPrivList` → 返回 17 条 | | `18:26:34~18:26:45` | 写入访问历史 `AccessHistoryMapper.insert` → 记录登录行为 | | `18:26:52` | 输出拦截器日志:用户 [JE02787] 访问 `/rrc/login.html` 耗时 **7675ms** | ✅ 整个登录流程完整且成功,所有数据库操作都在事务控制下完成,SqlSession 正常释放。 --- #### 2. 邮件通知任务自动执行(关键线索) ```log 2025-10-04 18:27:03,480 DEBUG com.sjsemi.rrc.task.MailNotificationTask - - RRC Auto Mail Send Complete ``` - 表明有一个名为 `MailNotificationTask` 的定时任务刚刚执行完毕。 - 在此之前有如下操作: ```log rrc.mybatis.mapper.MailNotificationMapper.updateNotification - < Updates: 1 ``` → 说明刚刚更新了一条邮件通知记录(ID=1006803),标记为已发送(MAIL_SEND_FLAG='1') 📌 这意味着: - 定时任务正在运行 - 使用了 `mailNotificationService.updateNotification(...)` - 并且能获取到 Connection → 当前还未完全断链 但注意:这次任务执行发生在 `18:27:03`,而后面出错的时间是 `18:30:28`,中间间隔约 **3分钟** —— 这正是问题积累的过程! --- #### 3. 关键信号:连接被重复使用 & 多连接并发 观察日志中的 JDBC Connection 地址变化: | Connection HashCode | 出现时间 | 用途 | |---------------------|---------|------| | `@5729a452` | 多次出现 | 主线程常用连接(可能是连接池第一个) | | `@2630bc2b` | 多次出现 | 第二个活跃连接 | | `@7c4ad7d6`, `@266f770f` | 后期出现 | 新建连接 | 🟢 前期多个 SqlSession 共享相同的 Connection(由 Spring 管理),属于正常现象(同一个事务可复用)。 🟡 但后期频繁“Creating a new SqlSession”+同 Connection → 可能已有连接未及时归还,新请求被迫新建连接。 ⚠️ 当连接数接近 Druid 最大值(默认 maxActive=8 或 20)时,就会开始排队等待,导致后续请求变慢甚至超时。 --- #### 4. 用户反馈:“签核完这一站后流到下一站,准备切换账号审核” 这句非常重要! 👉 用户 `JE02787` 是从另一个账号(比如 `JE03427`)切换过来的。 这意味着: - 用户可能打开了多个浏览器标签页 - 或者前后台共多个会话(session) - 每个请求都会占用一个线程 + 可能获取数据库连接 - 如果系统中有“流程推自动触发邮件”机制,则每一步流转都可能触发一次 `MailNotificationTask` 💡 推测场景: 1. `JE03427` 完成审批 → 流程推 → 触发邮件任务 A 2. 邮件任务 A 启动子线程发送邮件,但未正确管理事务 3. `JE02787` 登录 → 又触发一次邮件任务 B(或其他事件) 4. 多个任务并发抢占连接池资源 5. 某个任务在线程间传递了 SqlSession 或 Connection → Druid 报 `get/close not same thread` 6. 连接无法归还 → 连接池耗尽 → 后续所有请求卡住 → 登录转圈 45 秒 --- ### 🧪 为什么第一次登录还能成功?第二次就行? | 第一次登录(18:26) | 第二次登录(18:28) | |--------------------|---------------------| | 连接池尚未耗尽 | 前面的任务已泄漏连接 | | 所有操作在主线程完成 | 可能有异步任务仍在运行 | | SqlSession 正常释放 | 新请求拿到连接 | | 耗时 7.6s(偏高但成功) | 耗时 44.6s(严重阻塞) | ➡️ 明显是一个**资源泄漏累积效应**: 第一次只是“慢”,第二次已经是“堵死了”。 --- ### ✅ 根本原因总结 | 问题 | 描述 | |------|------| | 🔴 **根本原因** | **数据库连接未正确释放或跨线程使用,导致连接池逐渐耗尽** | | 🟡 **直接表现** | `DruidDataSource - get/close not same thread` + `connection holder is null` | | 🟡 **诱因** | 用户频繁切换、流程自动触发任务、定时任务并发执行 | | 🟡 **代码隐患** | 极可能在以下任意一种:<br>• 使用 `@Async` 异步方法调用 Service<br>• 手动启用了线程池执行数据库操作<br>• 自定义线程中调用了 DAO<br>• 没有配置 `removeAbandoned=true` 导致泄漏无法回收 | --- ### ✅ 解决方案建议 #### ✅ 1. 检查 `MailNotificationTask` 是否使用了异步线程 ```java @Component public class MailNotificationTask { @Autowired private MailNotificationService mailNotificationService; @Scheduled(fixedDelay = 5000) public void sendPendingMails() { // ❌ 危险!如果下面的操作开了子线程? executor.submit(() -> { MailNotification mail = service.findUnSendTopRecord(); // ... }); } } ``` ✅ 应改为: ```java @Scheduled(fixedDelay = 5000) public void sendPendingMails() { // ✅ 全部操作放在主线程中 List<MailNotification> mails = mailNotificationService.findUnSendTopRecord(); for (MailNotification mail : mails) { try { boolean success = sendEmail(mail); if (success) { mail.setMailSendFlag("1"); mail.setMailSendTime(new Date()); mailNotificationService.updateNotification(mail); } } catch (Exception e) { log.error("Failed to send mail ID:" + mail.getId(), e); } } } ``` #### ✅ 2. 配置 Druid 连接泄漏监控 ```yaml # application.yml spring: datasource: druid: remove-abandoned: true remove-abandoned-timeout: 300 # 超过5分钟未关闭即视为泄漏 log-abandoned: true # 打印堆栈 ``` 重启后,一旦发生泄漏,Druid 会在日志中输出谁打开了这个连接,便于定位。 #### ✅ 3. 添加 SQL 执行耗时监控 AOP ```java @Aspect @Component public class SlowSqlLogger { private static final long SLOW_THRESHOLD = 3000; // 3秒以上为慢查询 @Around("execution(* org.apache.ibatis.session.SqlSession.*(..))") public Object logTime(CProceedingJoinPoint pjp) throws Throwable { long start = System.currentTimeMillis(); Object result = pjp.proceed(); long elapsed = System.currentTimeMillis() - start; if (elapsed > SLOW_THRESHOLD) { System.out.println("SLOW SQL DETECTED: " + pjp.getSignature() + " took " + elapsed + "ms"); Thread.dumpStack(); } return result; } } ``` --- ###
评论
成就一亿技术人!
拼手气红包6.0元
还能输入1000个字符  | 博主筛选后可见
 
红包 添加红包
表情包 插入表情
 条评论被折叠 查看
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值