«Превышено время ожидания блокировки; попробуйте перезапустить транзакцию» для моего запроса на удаление - PullRequest
Новая
       88

«Превышено время ожидания блокировки; попробуйте перезапустить транзакцию» для моего запроса на удаление

0 голосов
/ 06 ноября 2019

  • Я использую RDS Aurora с MySQL 5.6.

  • У меня есть запрос на удаление таблицы, которая запускается один раз в день, и она не работает с блокировкойвремя ожидания, попробуйте перезапустить транзакцию.

  • Эта проблема не происходит регулярно, она происходит очень случайно, что затрудняет анализ.
  • Я не использую какие-либо явные транзакции, такие как использование начала. AutoCommit включен, и уровень изоляции транзакции по умолчанию
    REPEATABLE READ).
  • Несколько операций вставки и выбора происходят в этой таблице очень часто.
  • Я понимаю, что он ждет 50 секунд, прежде чем отказаться.
  • Я получил статус Innodb и список процессов. Я видел, что некоторые транзакции активны в течение долгого времени, например, 17 часов. В некоторых случаях статус показывает, что некоторые блокирующие транзакции ожидают 390 секунд
  • С последующим включением схемы производительности (https://www.psce.com/en/blog/2015/01/22/tracking-mysql-query-history-in-long-running-transactions/) Возможность получить несколькозапросы с одинаковым идентификатором потока, возможно, они
    могут использовать одно и то же соединение из пула Tomcat.

Схема таблицы 

CREATE TABLE EVENT_DETAILS
(
  ORG_ID CHAR(32) NOT NULL,
  CONFIG_KEY CHAR(32) NOT NULL,
  COMPONENT_NAME VARCHAR(512) NOT NULL,
  REQUEST_ID  CHAR(32) NOT NULL,
  UPDATE_DATE INT NOT NULL,
  UPDATE_TIME INT NOT NULL,
  CLIENT CHAR(16) NOT NULL,
  STATUS INT NOT NULL,
  EVENT_DATA VARCHAR(1024),
  MESSAGE VARCHAR(512),
  INSERTED_TIME     TIMESTAMP      DEFAULT CURRENT_TIMESTAMP NOT NULL,
  INDEX STATE_INDEX  (UPDATE_DATE, UPDATE_TIME, ORG_ID, CONFIG_KEY, COMPONENT_NAME, STATUS, CLIENT)
);

Таблица не имеет первичных ключей и индексане является уникальным. 

------------
TRANSACTIONS
------------
Trx id counter 39664912
Purge done for trx's n:o < 39661203 undo n:o < 0 state: running but idle
History list length 1207
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 39664853, not started
MySQL thread id 269, OS thread handle 0x2b90a2ee3700, query id 657304 10.103.88.40 administrator cleaned up
---TRANSACTION 39664826, not started
MySQL thread id 268, OS thread handle 0x2b90a2ea2700, query id 657292 10.103.88.40 administrator cleaned up
---TRANSACTION 39664892, not started
MySQL thread id 267, OS thread handle 0x2b90a2ea2700, query id 657343 10.103.88.40 administrator cleaned up
---TRANSACTION 39663626, not started
MySQL thread id 262, OS thread handle 0x2b90a2fe7700, query id 657356 10.103.88.40 administrator init
SHOW ENGINE INNODB STATUS
---TRANSACTION 39664820, not started
MySQL thread id 254, OS thread handle 0x2b90a2ea2700, query id 657289 10.103.88.40 administrator delayed commit ok done
---TRANSACTION 39663144, not started
MySQL thread id 247, OS thread handle 0x2b9070f88700, query id 656951 10.103.88.51 administrator cleaned up
---TRANSACTION 39661868, not started
MySQL thread id 234, OS thread handle 0x2b9070f88700, query id 654548 10.103.88.40 administrator cleaned up
---TRANSACTION 39664902, not started
MySQL thread id 194, OS thread handle 0x2b90d3a40700, query id 657346 10.103.88.51 administrator cleaned up
---TRANSACTION 39640759, not started
MySQL thread id 184, OS thread handle 0x2b9070fc9700, query id 629172 10.103.88.51 administrator delayed commit ok done
---TRANSACTION 39652587, not started
MySQL thread id 138, OS thread handle 0x2b90a2ee3700, query id 639886 10.103.88.51 administrator delayed commit ok done
---TRANSACTION 39664865, not started
MySQL thread id 128, OS thread handle 0x2b90a2ee3700, query id 657315 10.103.88.40 administrator cleaned up
---TRANSACTION 39663665, not started
MySQL thread id 62, OS thread handle 0x2b90a2fe7700, query id 656200 10.103.88.51 administrator cleaned up
---TRANSACTION 39664440, not started
MySQL thread id 93, OS thread handle 0x2b90a2fa6700, query id 656949 10.103.89.37 administrator cleaned up
---TRANSACTION 39659236, not started
MySQL thread id 63, OS thread handle 0x2b90a2ea2700, query id 652337 10.103.88.51 administrator cleaned up
---TRANSACTION 39663987, not started
MySQL thread id 39, OS thread handle 0x2b9070f88700, query id 656514 10.103.88.40 administrator cleaned up
---TRANSACTION 39662986, not started
MySQL thread id 21, OS thread handle 0x2b9068f86700, query id 655533 localhost rdsadmin delayed send ok done
---TRANSACTION 39664637, not started
MySQL thread id 1, OS thread handle 0x2b9068fc7700, query id 657349 localhost rdsadmin delayed send ok done
---TRANSACTION 39664682, not started
MySQL thread id 3, OS thread handle 0x2b9068fc7700, query id 657190 localhost rdsadmin cleaned up
---TRANSACTION 39664906, not started
MySQL thread id 2, OS thread handle 0x2b9070ec5700, query id 657355 localhost rdsadmin delayed send ok done
---TRANSACTION 39664531, ACTIVE 36 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 6139 lock struct(s), heap size 376, 116083 row lock(s)
MySQL thread id 275, OS thread handle 0x2b90a2e61700, query id 657035 10.103.89.37 administrator updating
DELETE from CONFIGSTOREQASTAGINGREL.EVENT_DETAILS where UPDATE_DATE < 20191015 AND COMPONENT_NAME = 'health'
------- TRX HAS BEEN WAITING 35 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 194 page no 10073 n bits 46 index `GEN_CLUST_INDEX` of table `CONFIGSTOREQASTAGINGREL`.`EVENT_DETAILS` trx id 39664531 lock_mode X waiting
Record lock, heap no 46 PHYSICAL RECORD: n_fields 14; compact format; info bits 0
 0: len=6; bufptr=0x2b90ac8ff23b; hex= 00000020fec2; asc       ;;
 1: len=6; bufptr=0x2b90ac8ff241; hex= 0000025d2e9d; asc    ]. ;;
 2: len=7; bufptr=0x2b90ac8ff247; hex= 9000001ad40110; asc        ;;
 3: len=30; bufptr=0x2b90ac8ff24e; hex= 653332333939633738383231626638616462323763653039383864393137; asc e32399c78821bf8adb27ce0988d917; (total 32 bytes);
 4: len=30; bufptr=0x2b90ac8ff26e; hex= 393962613134393834643637393236396639353936343538346632323630; asc 99ba14984d679269f95964584f2260; (total 32 bytes);
 5: len=30; bufptr=0x2b90ac8ff28e; hex= 706372732d484953544f524943414c2d506f77657243656e7465725f5265; asc pcrs-HISTORICAL-PowerCenter_Re; (total 38 bytes);
 6: len=30; bufptr=0x2b90ac8ff2b4; hex= 344b3433373444353468636947336c534464563371622020202020202020; asc 4K4374D54hciG3lSDdV3qb        ; (total 32 bytes);
 7: len=4; bufptr=0x2b90ac8ff2d4; hex= 81341728; asc  4 (;;
 8: len=4; bufptr=0x2b90ac8ff2d8; hex= 80000282; asc     ;;
 9: len=16; bufptr=0x2b90ac8ff2dc; hex= 646174612d636f6c6c6563746f722020; asc data-collector  ;;
 10: len=4; bufptr=0x2b90ac8ff2ec; hex= 80000001; asc     ;;
 11: len=30; bufptr=0x2b90ac8ff2f0; hex= 393962613134393834643637393236396639353936343538346632323630; asc 99ba14984d679269f95964584f2260; (total 245 bytes);
 12: len=30; bufptr=0x2b90ac8ff3e5; hex= 436f6c6c656374696f6e20636f6d706c6574656420737563636573736675; asc Collection completed successfu; (total 33 bytes);
 13: len=4; bufptr=0x2b90ac8ff406; hex= 5da6bbe9; asc ]   ;;

------------------
---TRANSACTION 39661213, ACTIVE 390 sec
4 lock struct(s), heap size 376, 6 row lock(s), undo log entries 34
MySQL thread id 245, OS thread handle 0x2b9070fc9700, query id 657295 10.103.88.40 administrator cleaned up
Trx read view will not see trx with id >= 39661214, sees < 39661213
--------





    mysql> show processlist;
+-----+---------------+--------------------+-------------------------+---------+------+------------------------+------------------------------------------------------------------------------------------------------+
| Id  | User          | Host               | db                      | Command | Time | State                  | Info                                                                                                 |
+-----+---------------+--------------------+-------------------------+---------+------+------------------------+------------------------------------------------------------------------------------------------------+
|   1 | rdsadmin      | localhost          | NULL                    | Sleep   |    1 | delayed send ok done   | NULL                                                                                                 |
|   2 | rdsadmin      | localhost          | NULL                    | Sleep   |    1 | delayed send ok done   | NULL                                                                                                 |
|   3 | rdsadmin      | localhost          | NULL                    | Sleep   |    4 | cleaned up             | NULL                                                                                                 |
|  21 | rdsadmin      | localhost          | NULL                    | Sleep   |  234 | delayed send ok done   | NULL                                                                                                 |
|  39 | administrator | 10.103.88.40:36280 | CONFIGSTOREQASTAGINGREL | Sleep   |  119 | cleaned up             | NULL                                                                                                 |
|  62 | administrator | 10.103.88.51:45652 | CONFIGSTOREQASTAGINGREL | Sleep   |    6 | cleaned up             | NULL                                                                                                 |
|  63 | administrator | 10.103.88.51:45654 | CONFIGSTOREQASTAGINGREL | Sleep   |  617 | cleaned up             | NULL                                                                                                 |
|  93 | administrator | 10.103.89.37:34512 | CONFIGSTOREQASTAGINGREL | Sleep   |   61 | cleaned up             | NULL                                                                                                 |
| 128 | administrator | 10.103.88.40:48708 | CONFIGSTOREQASTAGINGREL | Sleep   |    1 | cleaned up             | NULL                                                                                                 |
| 138 | administrator | 10.103.88.51:54406 | CONFIGSTOREQASTAGINGREL | Sleep   | 1413 | delayed commit ok done | NULL                                                                                                 |
| 184 | administrator | 10.103.88.51:60550 | CONFIGSTOREQASTAGINGREL | Sleep   | 2765 | delayed commit ok done | NULL                                                                                                 |
| 194 | administrator | 10.103.88.51:36468 | RCSQASTAGINGREL         | Sleep   |    1 | cleaned up             | NULL                                                                                                 |
| 234 | administrator | 10.103.88.40:39282 | CONFIGSTOREQASTAGINGREL | Sleep   |  335 | cleaned up             | NULL                                                                                                 |
| 245 | administrator | 10.103.88.40:34848 | CONFIGSTOREQASTAGINGREL | Sleep   |   19 | cleaned up             | NULL                                                                                                 |
| 247 | administrator | 10.103.88.51:46624 | CONFIGSTOREQASTAGINGREL | Sleep   |   60 | cleaned up             | NULL                                                                                                 |
| 254 | administrator | 10.103.88.40:41764 | CONFIGSTOREQASTAGINGREL | Sleep   |   19 | delayed commit ok done | NULL                                                                                                 |
| 261 | administrator | 10.103.88.40:45674 | NULL                    | Sleep   |  853 | cleaned up             | NULL                                                                                                 |
| 262 | administrator | 10.103.88.40:47332 | CONFIGSTOREQASTAGINGREL | Query   |    0 | init                   | show processlist                                                                                     |
| 263 | administrator | 10.103.89.26:47910 | CONFIGSTOREQASTAGINGREL | Sleep   |  535 | delayed send ok done   | NULL                                                                                                 |
| 267 | administrator | 10.103.88.40:49682 | CONFIGSTOREQASTAGINGREL | Sleep   |    7 | delayed commit ok done | NULL                                                                                                 |
| 268 | administrator | 10.103.88.40:49684 | CONFIGSTOREQASTAGINGREL | Sleep   |   19 | cleaned up             | NULL                                                                                                 |
| 269 | administrator | 10.103.88.40:49686 | CONFIGSTOREQASTAGINGREL | Sleep   |   18 | cleaned up             | NULL                                                                                                 |
| 275 | administrator | 10.103.89.37:47946 | CONFIGSTOREQASTAGINGREL | Query   |   46 | updating               | DELETE from CONFIGSTOREQASTAGINGREL.EVENT_DETAILS where UPDATE_DATE < 20191015 AND COMPONENT_NAME =  |
+-----+---------------+--------------------+-------------------------+---------+------+------------------------+------------------------------------------------------------------------------------------------------+
23 rows in set (0.00 sec)

Мое намерение состояло в том, чтобы идентифицировать блокирующую транзакцию, а не уничтожать поток, чтобы я мог исправить свой код вместо того, чтобы постоянно убивать блокирующий поток. 

mysql> SELECT r.trx_id waiting_trx_id,
    -> r.trx_mysql_thread_id waiting_thread,
    -> r.trx_query waiting_query,
    -> b.trx_id blocking_trx_id,
    -> b.trx_mysql_thread_id blocking_thread,
    -> b.trx_query blocking_query
    -> FROM information_schema.innodb_lock_waits w
    -> INNER JOIN information_schema.innodb_trx b ON
    -> b.trx_id = w.blocking_trx_id
    -> INNER JOIN information_schema.innodb_trx r ON
    -> r.trx_id = w.requesting_trx_id;
+----------------+----------------+--------------------------------------------------------------------------------------------------------------+-----------------+-----------------+----------------+
| waiting_trx_id | waiting_thread | waiting_query                                                                                                | blocking_trx_id | blocking_thread | blocking_query |
+----------------+----------------+--------------------------------------------------------------------------------------------------------------+-----------------+-----------------+----------------+
| 39664531       |            275 | DELETE from CONFIGSTOREQASTAGINGREL.EVENT_DETAILS where UPDATE_DATE < 20191015 AND COMPONENT_NAME = 'health' | 39661213        |             245 | NULL           |
+----------------+----------------+--------------------------------------------------------------------------------------------------------------+-----------------+-----------------+----------------+
1 row in set (0.00 sec)



mysql> select * from information_schema.innodb_trx where trx_id = 39661213;
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
| 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 |
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
| 39661213 | RUNNING   | 2019-10-16 06:42:39 | NULL                  | NULL             |         38 |                 245 | NULL      | NULL                |                 0 |                 0 |                4 |                   376 |               6 |                34 |                       0 | REPEATABLE READ     |                 1 |                      1 | NULL                       |                         0 |                         0 |                0 |                          0 |
+----------+-----------+---------------------+-----------------------+------------------+------------+---------------------+-----------+---------------------+-------------------+-------------------+------------------+-----------------------+-----------------+-------------------+-------------------------+---------------------+-------------------+------------------------+----------------------------+---------------------------+---------------------------+------------------+----------------------------+
1 row in set (0.00 sec)
...