Một trong những lỗi phổ biến nhất của InnoDB là vượt quá thời gian chờ của khóa InnoDB, ví dụ:
SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transactionỞ trên chỉ đơn giản có nghĩa là giao dịch đã đạt đến innodb_lock_wait_timeout trong khi chờ nhận được khóa độc quyền được đặt mặc định là 50 giây. Các nguyên nhân phổ biến là:
- Giao dịch tấn công không đủ nhanh để cam kết hoặc khôi phục giao dịch trong thời hạn innodb_lock_wait_timeout.
- Giao dịch tấn công đang chờ khóa hàng được giải phóng bởi một giao dịch khác.
Ảnh hưởng của Thời gian chờ Khóa InnoDB
Thời gian chờ của khóa InnoDB có thể gây ra hai tác động chính:
- Câu lệnh bị lỗi không được khôi phục theo mặc định.
- Ngay cả khi innodb_rollback_on_timeout được bật, khi một câu lệnh không thành công trong một giao dịch, ROLLBACK vẫn là một hoạt động tốn kém hơn COMMIT.
Hãy xem qua một ví dụ đơn giản để hiểu rõ hơn về hiệu ứng. Hãy xem xét hai bảng sau trong cơ sở dữ liệu mydb:
mysql> CREATE SCHEMA mydb;
mysql> USE mydb;Bảng đầu tiên (table1):
mysql> CREATE TABLE table1 ( id INT PRIMARY KEY AUTO_INCREMENT, data VARCHAR(50));
mysql> INSERT INTO table1 SET data = 'data #1';Bảng thứ hai (table2):
mysql> CREATE TABLE table2 LIKE table1;
mysql> INSERT INTO table2 SET data = 'data #2';Chúng tôi đã thực hiện các giao dịch của mình trong hai phiên khác nhau theo thứ tự sau:
| Đặt hàng | Giao dịch số 1 (T1) | Giao dịch số 2 (T2) |
| 1 | CHỌN * TỪ table1; (Được) | CHỌN * TỪ table1; (Được) |
| 2 | CẬP NHẬT table1 SET data ='T1 đang cập nhật hàng' WHERE id =1; (Được) | |
| 3 | CẬP NHẬT table2 SET data ='T2 đang cập nhật hàng' WHERE id =1; (Được) | |
| 4 | CẬP NHẬT table1 SET data ='T2 đang cập nhật hàng' WHERE id =1; (Treo một lúc và cuối cùng trả về lỗi "Đã vượt quá thời gian chờ khóa; thử khởi động lại giao dịch") | |
| 5 | CAM KẾT; (Được) | |
| 6 | CAM KẾT; (Được) |
mysql> SELECT * FROM table1 WHERE id = 1;
+----+-----------------------------------+
| id | data |
+----+-----------------------------------+
| 1 | T1 is updating the row |
+----+-----------------------------------+
mysql> SELECT * FROM table2 WHERE id = 1;
+----+-----------------------------------+
| id | data |
+----+-----------------------------------+
| 1 | T2 is updating the row |
+----+-----------------------------------+Sau khi T2 được cam kết thành công, người ta sẽ mong đợi nhận được cùng một kết quả "T2 đang cập nhật hàng" cho cả table1 và table2 nhưng kết quả cho thấy chỉ có table2 được cập nhật. Người ta có thể nghĩ rằng nếu có bất kỳ lỗi nào gặp phải trong một giao dịch, tất cả các câu lệnh trong giao dịch sẽ tự động được khôi phục lại hoặc nếu một giao dịch được cam kết thành công, toàn bộ câu lệnh sẽ được thực thi nguyên tử. Điều này đúng với deadlock, nhưng không đúng với thời gian chờ của khóa InnoDB.
Trừ khi bạn đặt innodb_rollback_on_timeout =1 (mặc định là 0 - bị vô hiệu hóa), việc khôi phục tự động sẽ không xảy ra đối với lỗi thời gian chờ khóa InnoDB. Điều này có nghĩa là, bằng cách tuân theo cài đặt mặc định, MySQL sẽ không bị lỗi và khôi phục toàn bộ giao dịch, cũng như không thử lại câu lệnh đã hết thời gian chờ và chỉ xử lý các câu lệnh tiếp theo cho đến khi nó đạt được COMMIT hoặc ROLLBACK. Điều này giải thích tại sao giao dịch T2 được cam kết một phần!
Tài liệu InnoDB nói rõ "InnoDB chỉ quay lại câu lệnh cuối cùng khi hết thời gian chờ giao dịch theo mặc định ". Trong trường hợp này, chúng tôi không nhận được tính nguyên tử của giao dịch do InnoDB cung cấp. Tính nguyên tử của giao dịch tuân thủ ACID là chúng tôi nhận được tất cả hoặc không có gì trong giao dịch, có nghĩa là giao dịch một phần chỉ không được chấp nhận.
Xử lý với thời gian chờ của khóa InnoDB
Vì vậy, nếu bạn đang mong đợi một giao dịch tự động khôi phục khi gặp lỗi chờ khóa InnoDB, tương tự như những gì sẽ xảy ra trong bế tắc, hãy đặt tùy chọn sau trong tệp cấu hình MySQL:
innodb_rollback_on_timeout=1Khởi động lại MySQL là bắt buộc. Khi triển khai một cụm dựa trên MySQL, ClusterControl sẽ luôn đặt innodb_rollback_on_timeout =1 trên mọi nút. Nếu không có tùy chọn này, ứng dụng của bạn phải thử lại câu lệnh không thành công hoặc thực hiện ROLLBACK một cách rõ ràng để duy trì tính nguyên tử của giao dịch.
Để xác minh xem cấu hình có được tải đúng hay không:
mysql> SHOW GLOBAL VARIABLES LIKE 'innodb_rollback_on_timeout';
+----------------------------+-------+
| Variable_name | Value |
+----------------------------+-------+
| innodb_rollback_on_timeout | ON |
+----------------------------+-------+Để kiểm tra xem cấu hình mới có hoạt động hay không, chúng tôi có thể theo dõi bộ đếm com_rollback khi lỗi này xảy ra:
mysql> SHOW GLOBAL STATUS LIKE 'com_rollback';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Com_rollback | 1 |
+---------------+-------+Theo dõi Giao dịch Chặn
Có một số nơi mà chúng tôi có thể xem xét để theo dõi giao dịch hoặc báo cáo chặn. Hãy bắt đầu bằng cách xem xét trạng thái công cụ InnoDB trong phần GIAO DỊCH:
mysql> SHOW ENGINE INNODB STATUS\G
------------
TRANSACTIONS
------------
...
---TRANSACTION 3100, ACTIVE 2 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 50, OS thread handle 139887555282688, query id 360 localhost ::1 root updating
update table1 set data = 'T2 is updating the row' where id = 1
------- TRX HAS BEEN WAITING 2 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 6 page no 4 n bits 72 index PRIMARY of table `mydb`.`table1` trx id 3100 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 80000001; asc ;;
1: len 6; hex 000000000c19; asc ;;
2: len 7; hex 020000011b0151; asc Q;;
3: len 22; hex 5431206973207570646174696e672074686520726f77; asc T1 is updating the row;;
------------------
---TRANSACTION 3097, ACTIVE 46 sec
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 48, OS thread handle 139887556167424, query id 358 localhost ::1 root
Trx read view will not see trx with id >= 3097, sees < 3097Từ thông tin trên, chúng ta có thể có cái nhìn tổng quan về các giao dịch hiện đang hoạt động trong máy chủ. Giao dịch 3097 hiện đang khóa một hàng cần được truy cập bởi giao dịch 3100. Tuy nhiên, kết quả ở trên không cho chúng tôi biết văn bản truy vấn thực tế có thể giúp chúng tôi tìm ra phần nào của truy vấn / câu lệnh / giao dịch mà chúng tôi cần điều tra thêm . Bằng cách sử dụng mã chuỗi MySQL 48 của trình chặn, hãy xem những gì chúng ta có thể thu thập từ danh sách quy trình MySQL:
mysql> SHOW FULL PROCESSLIST;
+----+-----------------+-----------------+--------------------+---------+------+------------------------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-----------------+-----------------+--------------------+---------+------+------------------------+-----------------------+
| 4 | event_scheduler | localhost | <null> | Daemon | 5146 | Waiting on empty queue | <null> |
| 10 | root | localhost:56042 | performance_schema | Query | 0 | starting | show full processlist |
| 48 | root | localhost:56118 | mydb | Sleep | 145 | | <null> |
| 50 | root | localhost:56122 | mydb | Sleep | 113 | | <null> |
+----+-----------------+-----------------+--------------------+---------+------+------------------------+-----------------------+Thread ID 48 hiển thị lệnh là 'Ngủ'. Tuy nhiên, điều này không giúp chúng tôi nhiều để biết câu lệnh nào chặn giao dịch kia. Điều này là do câu lệnh trong giao dịch này đã được thực hiện và giao dịch đang mở này về cơ bản không làm gì cả vào lúc này. Chúng tôi cần tìm hiểu sâu hơn để xem điều gì đang xảy ra với chuỗi này.
Đối với MySQL 8.0, công cụ chờ khóa InnoDB có sẵn trong bảng data_lock_waits bên trong cơ sở dữ liệu performance_schema (hoặc bảng innodb_lock_waits bên trong cơ sở dữ liệu sys). Nếu sự kiện chờ khóa đang diễn ra, chúng ta sẽ thấy một cái gì đó như sau:
mysql> SELECT * FROM performance_schema.data_lock_waits\G
***************************[ 1. row ]***************************
ENGINE | INNODB
REQUESTING_ENGINE_LOCK_ID | 139887595270456:6:4:2:139887487554680
REQUESTING_ENGINE_TRANSACTION_ID | 3100
REQUESTING_THREAD_ID | 89
REQUESTING_EVENT_ID | 8
REQUESTING_OBJECT_INSTANCE_BEGIN | 139887487554680
BLOCKING_ENGINE_LOCK_ID | 139887595269584:6:4:2:139887487548648
BLOCKING_ENGINE_TRANSACTION_ID | 3097
BLOCKING_THREAD_ID | 87
BLOCKING_EVENT_ID | 9
BLOCKING_OBJECT_INSTANCE_BEGIN | 139887487548648Lưu ý rằng trong MySQL 5.6 và 5.7, thông tin tương tự được lưu trữ bên trong bảng innodb_lock_waits dưới cơ sở dữ liệu information_schema. Chú ý đến giá trị BLOCKING_THREAD_ID. Chúng tôi có thể sử dụng thông tin này để tìm kiếm tất cả các câu lệnh đang được thực thi bởi chuỗi này trong bảng events_statements_history:
mysql> SELECT * FROM performance_schema.events_statements_history WHERE `THREAD_ID` = 87;
0 rows in setCó vẻ như thông tin chủ đề không còn ở đó nữa. Chúng tôi có thể xác minh bằng cách kiểm tra giá trị tối thiểu và tối đa của cột thread_id trong bảng events_statements_history với truy vấn sau:
mysql> SELECT min(`THREAD_ID`), max(`THREAD_ID`) FROM performance_schema.events_statements_history;
+------------------+------------------+
| min(`THREAD_ID`) | max(`THREAD_ID`) |
+------------------+------------------+
| 98 | 129 |
+------------------+------------------+Chủ đề mà chúng tôi đang tìm kiếm (87) đã bị cắt bớt khỏi bảng. Chúng tôi có thể xác nhận điều này bằng cách xem kích thước của bảng event_statements_history:
mysql> SELECT @@performance_schema_events_statements_history_size;
+-----------------------------------------------------+
| @@performance_schema_events_statements_history_size |
+-----------------------------------------------------+
| 10 |
+-----------------------------------------------------+Điều trên có nghĩa là sự kiện_statements_history chỉ có thể lưu trữ 10 luồng cuối cùng. May mắn thay, performance_schema có một bảng khác để lưu trữ nhiều hàng hơn được gọi là event_statements_history_long, bảng này lưu trữ thông tin tương tự nhưng cho tất cả các chuỗi và nó có thể chứa nhiều hàng hơn:
mysql> SELECT @@performance_schema_events_statements_history_long_size;
+----------------------------------------------------------+
| @@performance_schema_events_statements_history_long_size |
+----------------------------------------------------------+
| 10000 |
+----------------------------------------------------------+Tuy nhiên, bạn sẽ nhận được kết quả trống nếu bạn cố gắng truy vấn bảng events_statements_history_long lần đầu tiên. Điều này được mong đợi vì theo mặc định, thiết bị này bị tắt trong MySQL như chúng ta có thể thấy trong bảng setup_consumers sau:
mysql> SELECT * FROM performance_schema.setup_consumers;
+----------------------------------+---------+
| NAME | ENABLED |
+----------------------------------+---------+
| events_stages_current | NO |
| events_stages_history | NO |
| events_stages_history_long | NO |
| events_statements_current | YES |
| events_statements_history | YES |
| events_statements_history_long | NO |
| events_transactions_current | YES |
| events_transactions_history | YES |
| events_transactions_history_long | NO |
| events_waits_current | NO |
| events_waits_history | NO |
| events_waits_history_long | NO |
| global_instrumentation | YES |
| thread_instrumentation | YES |
| statements_digest | YES |
+----------------------------------+---------+Để kích hoạt bảng event_statements_history_long, chúng ta cần cập nhật bảng setup_consumers như sau:
mysql> UPDATE performance_schema.setup_consumers SET enabled = 'YES' WHERE name = 'events_statements_history_long';Xác minh xem có hàng trong bảng events_statements_history_long ngay bây giờ không:
mysql> SELECT count(`THREAD_ID`) FROM performance_schema.events_statements_history_long;
+--------------------+
| count(`THREAD_ID`) |
+--------------------+
| 4 |
+--------------------+Ngầu. Bây giờ chúng ta có thể đợi cho đến khi sự kiện đợi khóa InnoDB tăng trở lại và khi nó đang diễn ra, bạn sẽ thấy hàng sau trong bảng data_lock_waits:
mysql> SELECT * FROM performance_schema.data_lock_waits\G
***************************[ 1. row ]***************************
ENGINE | INNODB
REQUESTING_ENGINE_LOCK_ID | 139887595270456:6:4:2:139887487555024
REQUESTING_ENGINE_TRANSACTION_ID | 3083
REQUESTING_THREAD_ID | 60
REQUESTING_EVENT_ID | 9
REQUESTING_OBJECT_INSTANCE_BEGIN | 139887487555024
BLOCKING_ENGINE_LOCK_ID | 139887595269584:6:4:2:139887487548648
BLOCKING_ENGINE_TRANSACTION_ID | 3081
BLOCKING_THREAD_ID | 57
BLOCKING_EVENT_ID | 8
BLOCKING_OBJECT_INSTANCE_BEGIN | 139887487548648Một lần nữa, chúng tôi sử dụng giá trị BLOCKING_THREAD_ID để lọc tất cả các câu lệnh đã được thực thi bởi chuỗi này so với bảng events_statements_history_long:
mysql> SELECT `THREAD_ID`,`EVENT_ID`,`EVENT_NAME`, `CURRENT_SCHEMA`,`SQL_TEXT` FROM events_statements_history_long
WHERE `THREAD_ID` = 57
ORDER BY `EVENT_ID`;
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
| THREAD_ID | EVENT_ID | EVENT_NAME | CURRENT_SCHEMA | SQL_TEXT |
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
| 57 | 1 | statement/sql/select | <null> | select connection_id() |
| 57 | 2 | statement/sql/select | <null> | SELECT @@VERSION |
| 57 | 3 | statement/sql/select | <null> | SELECT @@VERSION_COMMENT |
| 57 | 4 | statement/com/Init DB | <null> | <null> |
| 57 | 5 | statement/sql/begin | mydb | begin |
| 57 | 7 | statement/sql/select | mydb | select 'T1 is in the house' |
| 57 | 8 | statement/sql/select | mydb | select * from table1 |
| 57 | 9 | statement/sql/select | mydb | select 'some more select' |
| 57 | 10 | statement/sql/update | mydb | update table1 set data = 'T1 is updating the row' where id = 1 |
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+Cuối cùng, chúng tôi đã tìm ra thủ phạm. Chúng ta có thể biết bằng cách nhìn vào chuỗi sự kiện của luồng 57 trong đó giao dịch ở trên (T1) vẫn chưa kết thúc (không có COMMIT hoặc ROLLBACK) và chúng ta có thể thấy câu lệnh cuối cùng đã nhận được một khóa độc quyền cho hàng để cập nhật hoạt động mà giao dịch kia cần (T2) và chỉ cần treo ở đó. Điều đó giải thích tại sao chúng ta thấy 'Sleep' trong đầu ra danh sách quy trình MySQL.
Như chúng ta có thể thấy, câu lệnh SELECT ở trên yêu cầu bạn phải lấy trước giá trị thread_id. Để đơn giản hóa truy vấn này, chúng ta có thể sử dụng mệnh đề IN và một truy vấn con để nối cả hai bảng. Truy vấn sau tạo ra kết quả giống hệt như trên:
mysql> SELECT `THREAD_ID`,`EVENT_ID`,`EVENT_NAME`, `CURRENT_SCHEMA`,`SQL_TEXT` from events_statements_history_long WHERE `THREAD_ID` IN (SELECT `BLOCKING_THREAD_ID` FROM data_lock_waits) ORDER BY `EVENT_ID`;
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
| THREAD_ID | EVENT_ID | EVENT_NAME | CURRENT_SCHEMA | SQL_TEXT |
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
| 57 | 1 | statement/sql/select | <null> | select connection_id() |
| 57 | 2 | statement/sql/select | <null> | SELECT @@VERSION |
| 57 | 3 | statement/sql/select | <null> | SELECT @@VERSION_COMMENT |
| 57 | 4 | statement/com/Init DB | <null> | <null> |
| 57 | 5 | statement/sql/begin | mydb | begin |
| 57 | 7 | statement/sql/select | mydb | select 'T1 is in the house' |
| 57 | 8 | statement/sql/select | mydb | select * from table1 |
| 57 | 9 | statement/sql/select | mydb | select 'some more select' |
| 57 | 10 | statement/sql/update | mydb | update table1 set data = 'T1 is updating the row' where id = 1 |
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+Tuy nhiên, chúng tôi không thực thi truy vấn trên bất cứ khi nào xảy ra sự kiện chờ khóa InnoDB. Ngoài lỗi từ ứng dụng, làm thế nào bạn biết rằng sự kiện chờ khóa đang diễn ra? Chúng tôi có thể tự động hóa việc thực thi truy vấn này bằng tập lệnh Bash đơn giản sau, được gọi là track_lockwait.sh:
$ cat track_lockwait.sh
#!/bin/bash
## track_lockwait.sh
## Print out the blocking statements that causing InnoDB lock wait
INTERVAL=5
DIR=/root/lockwait/
[ -d $dir ] || mkdir -p $dir
while true; do
check_query=$(mysql -A -Bse 'SELECT THREAD_ID,EVENT_ID,EVENT_NAME,CURRENT_SCHEMA,SQL_TEXT FROM events_statements_history_long WHERE THREAD_ID IN (SELECT BLOCKING_THREAD_ID FROM data_lock_waits) ORDER BY EVENT_ID')
# if $check_query is not empty
if [[ ! -z $check_query ]]; then
timestamp=$(date +%s)
echo $check_query > $DIR/innodb_lockwait_report_${timestamp}
fi
sleep $INTERVAL
doneÁp dụng quyền thực thi và daemonize tập lệnh ở chế độ nền:
$ chmod 755 track_lockwait.sh
$ nohup ./track_lockwait.sh &Bây giờ, chúng ta chỉ cần đợi các báo cáo được tạo trong thư mục / root / lockwait. Tùy thuộc vào khối lượng công việc cơ sở dữ liệu và các mẫu truy cập hàng, bạn có thể thấy nhiều tệp trong thư mục này. Theo dõi chặt chẽ thư mục nếu không nó sẽ bị tràn ngập với quá nhiều tệp báo cáo.
Nếu bạn đang sử dụng ClusterControl, bạn có thể bật tính năng Nhật ký giao dịch trong Hiệu suất -> Nhật ký giao dịch, trong đó ClusterControl sẽ cung cấp báo cáo về các lần bế tắc và các giao dịch đang hoạt động lâu dài, điều này sẽ giúp bạn dễ dàng hơn trong việc tìm ra thủ phạm.
Kết luận
Tóm lại, nếu chúng ta gặp lỗi "Lock Wait Timeout Exceeded" trong MySQL, trước tiên chúng ta cần hiểu những ảnh hưởng mà lỗi đó có thể gây ra đối với cơ sở hạ tầng của chúng ta, sau đó theo dõi giao dịch tấn công và hành động nó hoặc với các tập lệnh shell như track_lockwait.sh hoặc phần mềm quản lý cơ sở dữ liệu như ClusterControl.
Nếu bạn quyết định sử dụng các tập lệnh shell, chỉ cần lưu ý rằng chúng có thể giúp bạn tiết kiệm tiền nhưng sẽ khiến bạn mất thời gian, vì bạn cần biết một hoặc hai điều về cách chúng hoạt động, hãy đăng ký quyền và có thể làm cho chúng chạy trong nền và nếu bạn bị lạc trong khu rừng có vỏ, chúng tôi có thể trợ giúp.
Dù bạn quyết định triển khai điều gì, hãy đảm bảo theo dõi chúng tôi trên Twitter hoặc đăng ký nguồn cấp dữ liệu RSS của chúng tôi để biết thêm mẹo về cải thiện hiệu suất của cả phần mềm của bạn và cơ sở dữ liệu hỗ trợ nó, chẳng hạn như bài đăng này bao gồm 6 trường hợp lỗi phổ biến trong MySQL.
