MySQL事务RUNNING状态引发的Transactiontimedout:deadline问题

首頁

資料庫

mysql教程

MySQL事务RUNNING状态引发的Transactiontimedout:deadline问题_MySQL

WBOYWBOYWBOYWBOYWBOYWBOYWBOYWBOYWBOYWBOYWBOYWBOYWB

Jun 01, 2016 pm 01:04 PM

事務狀態問題

前言：
朋友说简单的查询导致Transaction timed out: deadline问题，怀疑是数据库表锁了，

1，应用故障描述Deadline问题：
--- The error occurred in META-INF/ibatis/ITEM_sqlmap.xml.
--- The error occurred while executing query.
--- Check the SELECT I.ID, I.SHOP_ID, I.ITEM_GROUP_ID, I.ITEM_GROUP_NAME, I.ITEM_NAME, I.LIST_PRICE, I.PL_PRICE, I.PROTECTION_PRICE, I.MALL, I.STAT, I.LOGISTICS, I.TYPE, I.ITEM_CATEGORY_ID, I.BRAND_ID, I.BRAND, I.FAVOUR_NUM, I.IS_SUBSCRIBE, I.VOLUME, I.WEIGHT, I.INVENTORY, I.RELEASE_DATE, I.OFF_REASON, I.IS_DEL, I.CREATED_DATE, I.UPDATED_DATE, I.SIMPLE_DESCRIPTION, I.VIRTUAL_BEGIN_DATE, I.VIRTUAL_END_DATE, I.SEQ_NUM, IPC.PICTURE_PATH FROM ITEM AS I INNER JOIN ITEM_PICTURE AS IPC ON I.ITEM_GROUP_ID = IPC.ITEM_GROUP_ID where I.ID = ? AND IPC.TYPE='1' AND IPC.IS_DEL='0' .
--- Check the SQL Statement (preparation failed).
--- Cause: org.springframework.transaction.TransactionTimedOutException: Transaction timed out: deadline was Tue Nov 25 13:33:07 CST 2014
at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeQueryWithCallback(MappedStatement.java:204)
at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeQueryForObject(MappedStatement.java:120)
at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlMapExecutorDelegate.java:518)
at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlMapExecutorDelegate.java:493)
at com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.queryForObject(SqlMapSessionImpl.java:106)
at org.springframework.orm.ibatis.SqlMapClientTemplate$1.doInSqlMapClient(SqlMapClientTemplate.java:273)
at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:203)
... 41 more
Caused by: org.springframework.transaction.TransactionTimedOutException: Transaction timed out: deadline was Tue Nov 25 13:33:07 CST 2014
at org.springframework.transaction.support.ResourceHolderSupport.checkTransactionTimeout(ResourceHolderSupport.java:141)
at org.springframework.transaction.support.ResourceHolderSupport.getTimeToLiveInMillis(ResourceHolderSupport.java:130)
at org.springframework.transaction.support.ResourceHolderSupport.getTimeToLiveInSeconds(ResourceHolderSupport.java:114)
at org.springframework.jdbc.datasource.DataSourceUtils.applyTimeout(DataSourceUtils.java:275)
at org.springframework.jdbc.datasource.DataSourceUtils.applyTransactionTimeout(DataSourceUtils.java:257)
at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:244)
at com.sun.proxy.$Proxy324.prepareStatement(Unknown Source)
at com.ibatis.sqlmap.engine.execution.SqlExecutor.prepareStatement(SqlExecutor.java:497)
at com.ibatis.sqlmap.engine.execution.SqlExecutor.executeQuery(SqlExecutor.java:175)
at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.sqlExecuteQuery(MappedStatement.java:221)
at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeQueryWithCallback(MappedStatement.java:189)
... 47 more

2，检查Innodb存储引擎状态以及表锁状态
SHOW ENINGE INNODB STATUS；没有死锁信息以及其它异常信息；去查询系统表INNODB_LOCKS、INNODB_LOCK_WAITS表都为NULL，只有INNODB_TRX表有记录，并且处于长时间RUNNING状态，判断是因为事务没有提交或者回滚的缘故。
mysql> SELECT * FROM `INNODB_TRX`;
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
| trx_id | trx_state | trx_started | trx_requested_lock_id | trx_wait_started | trx_weight | trx_mysql_thread_id | trx_query | trx_operation_state | trx_tables_in_use | trx_tables_locked | trx_lock_structs | trx_lock_memory_bytes | trx_rows_locked | trx_rows_modified | trx_concurrency_tickets | trx_isolation_level | trx_unique_checks | trx_foreign_key_checks | trx_last_foreign_key_error | trx_adaptive_hash_latched | trx_adaptive_hash_timeout | trx_is_read_only | trx_autocommit_non_locking |
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
| 19183390 | RUNNING | 2014-11-25 15:39:30 | NULL | NULL | 9 | 940341 | NULL | NULL | 0 | 0 | 5 | 1248 | 3 | 4 | 0 | READ COMMITTED | 1 | 1 | NULL | 0 | 9762 | 0 | 0 |
| 19183153 | RUNNING | 2014-11-25 15:36:41 | NULL | NULL | 0 | 940206 | NULL | NULL | 0 | 0 | 0 | 376 | 0 | 0 | 0 | READ COMMITTED | 1 | 1 | NULL | 0 | 9411 | 0 | 0 |
| 19183139 | RUNNING | 2014-11-25 15:36:28 | NULL | NULL | 0 | 940238 | NULL | NULL | 0 | 0 | 0 | 376 | 0 | 0 | 0 | READ COMMITTED | 1 | 1 | NULL | 0 | 9937 | 0 | 0 |
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
3 rows in set (0.00 sec)

mysql> SELECT * FROM `INNODB_LOCKS`;
Empty set (0.00 sec)

mysql> SELECT * FROM `INNODB_LOCK_WAITS`;
Empty set (0.00 sec)

mysql>

仔细check从中可以看出，没有表锁，没有行锁，没有锁等待，只有事务RUNNING没有提交或者回滚。临时解决办法，kill掉这些事务所在的线程。

3，问题重现，查看事务表记录
mysql> SELECT * FROM `INNODB_TRX`;
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
| trx_id | trx_state | trx_started | trx_requested_lock_id | trx_wait_started | trx_weight | trx_mysql_thread_id | trx_query | trx_operation_state | trx_tables_in_use | trx_tables_locked | trx_lock_structs | trx_lock_memory_bytes | trx_rows_locked | trx_rows_modified | trx_concurrency_tickets | trx_isolation_level | trx_unique_checks | trx_foreign_key_checks | trx_last_foreign_key_error | trx_adaptive_hash_latched | trx_adaptive_hash_timeout | trx_is_read_only | trx_autocommit_non_locking |
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
| 19196180 | RUNNING | 2014-11-25 17:41:10 | NULL | NULL | 12 | 942663 | NULL | NULL | 0 | 0 | 4 | 1248 | 2 | 8 | 0 | READ COMMITTED | 1 | 1 | NULL | 0 | 9810 | 0 | 0 |
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
1 rows in set (0.00 sec)

mysql>

4，去Slow log和binlog里面分析
去slow log里面看942663线程ID的slow记录，没有找到， 去看binlog里面942663线程ID的DML记录，有如下2条记录：
#141125 17:41:10 server id 230 end_log_pos 118147 CRC32 0x6f2402a1 Query thread_id=942663 exec_time=0 error_code=0
SET TIMESTAMP=1416908470/*!*/;
BEGIN
/*!*/;
# at 118147
#141125 17:41:10 server id 230 end_log_pos 118231 CRC32 0x0219bed2 Table_map: `business_db`.`SHOP_CASH_COUPON_USER_REF` mapped to number 178
# at 118231
#141125 17:41:10 server id 230 end_log_pos 118298 CRC32 0xc6665994 Write_rows: table id 178 flags: STMT_END_F
### INSERT INTO `business_db`.`SHOP_CASH_COUPON_USER_REF`
### SET
### @1=4859
### @2=284
### @3=2425
### @4='0'
### @5='2014-11-25 17:41:10'
### @6=NULL
# at 118298
#141125 17:41:10 server id 230 end_log_pos 118411 CRC32 0x93f6d105 Table_map: `business_db`.`CASH_TICKET` mapped to number 727
# at 118411
#141125 17:41:10 server id 230 end_log_pos 118703 CRC32 0xe4b314ad Update_rows: table id 727 flags: STMT_END_F
### UPDATE `business_db`.`CASH_TICKET`
### WHERE
### @1=19956
### @2=1416886592
### @3=NULL
### @4=NULL
### @5=1
### @6='2014-12-31 00:00:00'
### @7='2014-11-25 00:00:00'
### @8=NULL
### @9=NULL
### @10=NULL
### @11=NULL
### @12=NULL
### @13=NULL
### @14=NULL
### @15=NULL
### @16='5c2483b3033b30c6b948d6a971c87f1d'
### @17='CASH-TICKET-1'
### @18='0'
### @19=000000050.000000000
### @20=NULL
### @21=284
### @22='0'
### SET
### @1=19956
### @2=1416908470
### @3='PL.1qaz2wsx'
### @4=NULL
### @5=1
### @6='2014-12-31 00:00:00'
### @7='2014-11-25 00:00:00'
### @8=NULL
### @9=2425
### @10='PL.1qaz2wsx'
### @11='1qaz2wsx@163.com'
### @12='4859'
### @13=NULL
### @14=NULL
### @15=NULL
### @16='5c2483b3033b30c6b948d6a971c87f1d'
### @17='CASH-TICKET-1'
### @18='0'
### @19=000000050.000000000
### @20=1416908470
### @21=284
### @22='0'
# at 118703
#141125 17:41:10 server id 230 end_log_pos 118734 CRC32 0x6949012e Xid = 16199116
COMMIT/*!*/;

看到这个执行成功的DML操作和一直RUNNING的事务时间上比较吻合，所以通过这binlog的INSERT语句和UPDATE语句，找到应用的一个业务模块的方法，发现其异常处理模块没有及时COMMIT和ROLLBACK的。
添加上ROLLBACK处理后，再测试N次，没有出现过报错信息，而执行SELECT * FROM `INNODB_TRX`;也没有记录，这表示事务都及时COMMIT或者ROLLBACK了。

5，期间遇到的额外问题
Cause: java.sql.SQLException: Cannot execute statement: impossible to write to binary log since BINLOG_FORMAT = STATEMENT and at least one table uses a storage engine limited to row-based logging. InnoDB is limited to row-logging when transaction isolation level is READ COMMITTED or READ UNCOMMITTED.; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:
--- The error occurred while applying a parameter map.
--- Check the ITEM.updateByInventory-InlineParameterMap.
--- Check the statement (update failed).
--- Cause: java.sql.SQLException: Cannot execute statement: impossible to write to binary log since BINLOG_FORMAT = STATEMENT and at least one table uses a storage engine limited to row-based logging. InnoDB is limited to row-logging when transaction isolation level is READ COMMITTED or READ UNCOMMITTED.
处理方法：将BINLOG_FORMAT设置成MIXED即可，SET GLOBAL BINLOG_FORMAT = MIXED;

6，总结
这个问题看似解决了，但是可能还有更多的细节没有梳理，为什么事务开启后没有ROLLBACK或者COMMIT，后续执行SELECT就会报错呢？自己想来是DML形成排它锁X，而查询是有共享锁S，X和S是互斥的（关于Innodb锁请参考：http://blog.itpub.net/26230597/viewspace-1315111/），所以就出问题了，至于源码层的底层分析，有待以后继续深究，如果有遇到此类问题的朋友，欢迎share下你的处理思路以及分析过程，谢谢。

----------------------------------------------------------------------------------------------------------------

原博客地址： http://blog.itpub.net/26230597/viewspace-1346680/
原作者：黄杉 (mchdba)
----------------------------------------------------------------------------------------------------------------

陳述

本文內容由網友自願投稿，版權歸原作者所有。本站不承擔相應的法律責任。如發現涉嫌抄襲或侵權的內容，請聯絡admin@php.cn

您什麼時候應該使用複合索引與多個單列索引？Apr 11, 2025 am 12:06 AM

在數據庫優化中，應根據查詢需求選擇索引策略：1.當查詢涉及多個列且條件順序固定時，使用複合索引；2.當查詢涉及多個列但條件順序不固定時，使用多個單列索引。複合索引適用於優化多列查詢，單列索引則適合單列查詢。

如何識別和優化MySQL中的慢速查詢？（慢查詢日誌，performance_schema）Apr 10, 2025 am 09:36 AM

要優化MySQL慢查詢，需使用slowquerylog和performance_schema：1.啟用slowquerylog並設置閾值，記錄慢查詢；2.利用performance_schema分析查詢執行細節，找出性能瓶頸並優化。

MySQL和SQL：開發人員的基本技能Apr 10, 2025 am 09:30 AM

MySQL和SQL是開發者必備技能。 1.MySQL是開源的關係型數據庫管理系統，SQL是用於管理和操作數據庫的標準語言。 2.MySQL通過高效的數據存儲和檢索功能支持多種存儲引擎，SQL通過簡單語句完成複雜數據操作。 3.使用示例包括基本查詢和高級查詢，如按條件過濾和排序。 4.常見錯誤包括語法錯誤和性能問題，可通過檢查SQL語句和使用EXPLAIN命令優化。 5.性能優化技巧包括使用索引、避免全表掃描、優化JOIN操作和提升代碼可讀性。

描述MySQL異步主奴隸複製過程。Apr 10, 2025 am 09:30 AM

MySQL異步主從復制通過binlog實現數據同步，提升讀性能和高可用性。 1)主服務器記錄變更到binlog；2)從服務器通過I/O線程讀取binlog；3)從服務器的SQL線程應用binlog同步數據。

mysql：簡單的概念，用於輕鬆學習Apr 10, 2025 am 09:29 AM

MySQL是一個開源的關係型數據庫管理系統。 1）創建數據庫和表：使用CREATEDATABASE和CREATETABLE命令。 2）基本操作：INSERT、UPDATE、DELETE和SELECT。 3）高級操作：JOIN、子查詢和事務處理。 4）調試技巧：檢查語法、數據類型和權限。 5）優化建議：使用索引、避免SELECT*和使用事務。

MySQL：數據庫的用戶友好介紹Apr 10, 2025 am 09:27 AM

MySQL的安裝和基本操作包括：1.下載並安裝MySQL，設置根用戶密碼；2.使用SQL命令創建數據庫和表，如CREATEDATABASE和CREATETABLE；3.執行CRUD操作，使用INSERT,SELECT,UPDATE,DELETE命令；4.創建索引和存儲過程以優化性能和實現複雜邏輯。通過這些步驟，你可以從零開始構建和管理MySQL數據庫。

InnoDB緩衝池如何工作，為什麼對性能至關重要？Apr 09, 2025 am 12:12 AM

InnoDBBufferPool通過將數據和索引頁加載到內存中來提升MySQL數據庫的性能。 1)數據頁加載到BufferPool中，減少磁盤I/O。 2)臟頁被標記並定期刷新到磁盤。 3)LRU算法管理數據頁淘汰。 4)預讀機制提前加載可能需要的數據頁。

MySQL：初學者的數據管理易用性Apr 09, 2025 am 12:07 AM

MySQL適合初學者使用，因為它安裝簡單、功能強大且易於管理數據。 1.安裝和配置簡單，適用於多種操作系統。 2.支持基本操作如創建數據庫和表、插入、查詢、更新和刪除數據。 3.提供高級功能如JOIN操作和子查詢。 4.可以通過索引、查詢優化和分錶分區來提升性能。 5.支持備份、恢復和安全措施，確保數據的安全和一致性。

See all articles