Detailed Explanation of Long Transaction Example in MySQL

  • 2021-12-13 09:52:44
  • OfStack

Foreword:

The series of articles "Getting Started with MySQL" has been finished. In the future, my articles will focus on MySQL, mainly recording the scenes encountered in recent work and study or my own feelings and thoughts. The follow-up articles may not be so coherent, but I still hope you will support me a lot. To get back to the point, this article mainly introduces the related contents of MySQL long transactions. For example, if we open a transaction, what will happen if it is not submitted or rolled back, and how to deal with the transaction waiting situation? This article will give you the answer.

Note: This article does not focus on transaction isolation levels and related characteristics. Instead, it introduces the hazards related to long transactions and the monitoring and processing methods. This article is an experiment based on MySQL version 5.7. 23, non-repeatable read (RR) isolation level.

1. What is a long transaction

First of all, we need to know what a long transaction is. As the name implies, it is a transaction that runs for a long time and has not been committed for a long time. It can also be called a large transaction. This kind of transaction often causes a lot of blocking and lock timeout, which is easy to cause master-slave delay, so we should try to avoid using long transactions.

Now I will show you how to open a transaction and simulate a long transaction:


# Suppose we have 1 Zhang stu_tb The table, structure and data are as follows 
mysql> show create table stu_tb\G
*************************** 1. row ***************************
  Table: stu_tb
Create Table: CREATE TABLE `stu_tb` (
 `increment_id` int(11) NOT NULL AUTO_INCREMENT COMMENT ' Self-increasing primary key ',
 `stu_id` int(11) NOT NULL COMMENT ' Student number ',
 `stu_name` varchar(20) DEFAULT NULL COMMENT ' Student name ',
 `create_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT ' Creation time ',
 `update_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT ' Modification time ',
 PRIMARY KEY (`increment_id`),
 UNIQUE KEY `uk_stu_id` (`stu_id`) USING BTREE
) ENGINE=InnoDB AUTO_INCREMENT=9 DEFAULT CHARSET=utf8 COMMENT=' Test student table '
1 row in set (0.01 sec)

mysql> select * from stu_tb;
+--------------+--------+----------+---------------------+---------------------+
| increment_id | stu_id | stu_name | create_time   | update_time   |
+--------------+--------+----------+---------------------+---------------------+
|   1 | 1001 | from1 | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
|   2 | 1002 | dfsfd | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
|   3 | 1003 | fdgfg | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
|   4 | 1004 | sdfsdf | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
|   5 | 1005 | dsfsdg | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
|   6 | 1006 | fgd  | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
|   7 | 1007 | fgds  | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
|   8 | 1008 | dgfsa | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
+--------------+--------+----------+---------------------+---------------------+
8 rows in set (0.00 sec)

# Explicitly open a transaction, available begin Or start transaction
mysql> start transaction;
Query OK, 0 rows affected (0.00 sec)

mysql> select * from stu_tb where stu_id = 1006 for update;
+--------------+--------+----------+---------------------+---------------------+
| increment_id | stu_id | stu_name | create_time   | update_time   |
+--------------+--------+----------+---------------------+---------------------+
|   6 | 1006 | fgd  | 2019-09-15 14:27:34 | 2019-09-15 14:27:34 |
+--------------+--------+----------+---------------------+---------------------+
1 row in set (0.01 sec)

# If we don't commit the last transaction in time, it becomes a long transaction, and when other sessions want to manipulate this data, it will 1 Just wait. 

2. How to find long transactions

When we encounter transaction waiting problems, the first thing we should do is to find the executing transaction. The table information_schema. INNODB_TRX contains the transaction information that is currently running inside innodb. This table gives the start time of the transaction, and we can get the running time of the transaction with a little operation.


mysql> select t.*,to_seconds(now())-to_seconds(t.trx_started) idle_time from INFORMATION_SCHEMA.INNODB_TRX t \G
*************************** 1. row ***************************
     trx_id: 6168
     trx_state: RUNNING
    trx_started: 2019-09-16 11:08:27
  trx_requested_lock_id: NULL
   trx_wait_started: NULL
    trx_weight: 3
  trx_mysql_thread_id: 11
     trx_query: NULL
  trx_operation_state: NULL
   trx_tables_in_use: 0
   trx_tables_locked: 1
   trx_lock_structs: 3
  trx_lock_memory_bytes: 1136
   trx_rows_locked: 2
   trx_rows_modified: 0
 trx_concurrency_tickets: 0
  trx_isolation_level: REPEATABLE READ
   trx_unique_checks: 1
 trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
 trx_adaptive_hash_latched: 0
 trx_adaptive_hash_timeout: 0
   trx_is_read_only: 0
trx_autocommit_non_locking: 0
     idle_time: 170

In the result idle_time is computed and is the duration of the transaction. But the transaction's trx_query is NUL, which does not mean that the transaction did not execute anything. A transaction may contain more than one SQL, and if SQL is finished, it will no longer be displayed. The current transaction is executing, and innodb does not know if sql will follow this transaction and when commit will follow. Therefore, trx_query cannot provide meaningful information.

What if we want to see the SQL executed by this transaction to see if we can kill long transactions? We can query with other system tables. The specific query SQL is as follows:


mysql> select now(),(UNIX_TIMESTAMP(now()) - UNIX_TIMESTAMP(a.trx_started)) diff_sec,b.id,b.user,b.host,b.db,d.SQL_TEXT from information_schema.innodb_trx a inner join
  -> information_schema.PROCESSLIST b
  -> on a.TRX_MYSQL_THREAD_ID=b.id and b.command = 'Sleep'
  -> inner join performance_schema.threads c ON b.id = c.PROCESSLIST_ID
  -> inner join performance_schema.events_statements_current d ON d.THREAD_ID = c.THREAD_ID;
+---------------------+----------+----+------+-----------+--------+-----------------------------------------------------+
| now()        | diff_sec | id | user | host   | db   | SQL_TEXT                      |
+---------------------+----------+----+------+-----------+--------+-----------------------------------------------------+
| 2019-09-16 14:06:26 |    54 | 17 | root | localhost | testdb | select * from stu_tb where stu_id = 1006 for update |
+---------------------+----------+----+------+-----------+--------+-----------------------------------------------------+

diff_sec in the above result has the same meaning as idle_time above, and both represent the number of seconds that this transaction lasts. SQL_TEXT represents the SQL that the transaction just executed. However, the above statement can only find the SQL last executed by the transaction. We know that one transaction may contain multiple SQL, so we want to inquire which SQL has been executed by this uncommitted transaction and whether it can be met. The answer is that the combination of events_statements_history system table can also meet the requirements. The following statement will query all SQL executed by this transaction:


mysql> select now(),(UNIX_TIMESTAMP(now()) - UNIX_TIMESTAMP(a.trx_started)) diff_sec,b.id,b.user,b.host,b.db,d.SQL_TEXT from information_schema.innodb_trx a inner join
  -> information_schema.PROCESSLIST b
  -> on a.TRX_MYSQL_THREAD_ID=b.id and b.command = 'Sleep'
  -> inner join performance_schema.threads c ON b.id = c.PROCESSLIST_ID
  -> inner join performance_schema.events_statements_current d ON d.THREAD_ID = c.THREAD_ID;
+---------------------+----------+----+------+-----------+--------+-----------------------------------------------------+
| now()        | diff_sec | id | user | host   | db   | SQL_TEXT                      |
+---------------------+----------+----+------+-----------+--------+-----------------------------------------------------+
| 2019-09-16 14:06:26 |    54 | 17 | root | localhost | testdb | select * from stu_tb where stu_id = 1006 for update |
+---------------------+----------+----+------+-----------+--------+-----------------------------------------------------+

From the above results, we can see all SQL executed by the transaction from 1 to now. When we query the relevant information of the transaction clearly, we can determine whether the transaction can be killed, so as not to affect other transactions and cause waiting phenomenon.

Under the slight expansion here, long transactions are easy to cause blocking or deadlock. Usually, we can first query the sys.innodb_lock_waits view to determine whether there is transaction blocking:


# Hypothesis 1 Transaction execution  select * from stu_tb where stu_id = 1006 for update
# In addition 1 Transaction execution  update stu_tb set stu_name = 'wang' where stu_id = 1006

mysql> select * from sys.innodb_lock_waits\G
*************************** 1. row ***************************
        wait_started: 2019-09-16 14:34:32
          wait_age: 00:00:03
        wait_age_secs: 3
        locked_table: `testdb`.`stu_tb`
        locked_index: uk_stu_id
         locked_type: RECORD
       waiting_trx_id: 6178
     waiting_trx_started: 2019-09-16 14:34:32
       waiting_trx_age: 00:00:03
   waiting_trx_rows_locked: 1
  waiting_trx_rows_modified: 0
         waiting_pid: 19
        waiting_query: update stu_tb set stu_name = 'wang' where stu_id = 1006
       waiting_lock_id: 6178:47:4:7
      waiting_lock_mode: X
       blocking_trx_id: 6177
        blocking_pid: 20
       blocking_query: NULL
      blocking_lock_id: 6177:47:4:7
     blocking_lock_mode: X
    blocking_trx_started: 2019-09-16 14:18:44
      blocking_trx_age: 00:15:51
  blocking_trx_rows_locked: 2
 blocking_trx_rows_modified: 0
   sql_kill_blocking_query: KILL QUERY 20
sql_kill_blocking_connection: KILL 20

The above results show the blocked SQL and the type of lock, and even more powerful, the statement to kill the session is also given. However, SQL that blocked session execution was not found. If we want to find more detailed information, we can use the following statement:


mysql> SELECT
  ->  tmp.*,
  ->  c.SQL_Text blocking_sql_text,
  ->  p.HOST blocking_host
  -> FROM
  ->  (
  ->  SELECT
  ->   r.trx_state wating_trx_state,
  ->   r.trx_id waiting_trx_id,
  ->   r.trx_mysql_thread_Id waiting_thread,
  ->   r.trx_query waiting_query,
  ->   b.trx_state blocking_trx_state,
  ->   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
  ->  ) tmp,
  ->  information_schema.PROCESSLIST p,
  ->  PERFORMANCE_SCHEMA.events_statements_current c,
  ->  PERFORMANCE_SCHEMA.threads t
  -> WHERE
  ->  tmp.blocking_thread = p.id
  ->  AND t.thread_id = c.THREAD_ID
  ->  AND t.PROCESSLIST_ID = p.id \G
*************************** 1. row ***************************
 wating_trx_state: LOCK WAIT
  waiting_trx_id: 6180
  waiting_thread: 19
   waiting_query: update stu_tb set stu_name = 'wang' where stu_id = 1006
blocking_trx_state: RUNNING
  blocking_trx_id: 6177
  blocking_thread: 20
  blocking_query: NULL
 blocking_sql_text: select * from stu_tb where stu_id = 1006 for update
   blocking_host: localhost

The above results are more clear. We can clearly see the statements executed by the blocked side and the blocked side transactions, which helps us to check and confirm whether we can kill the blocked session.

3. Supervisor General Affairs

In real work, we need to monitor long transactions and define a threshold. For example, transactions with 30s execution time exceeding 30s are long transactions, which require recording and alarming to remind managers to deal with them. The following monitoring script is given. You can refer to it and change it according to your needs:


#!/bin/bash
# -------------------------------------------------------------------------------
# FileName:  long_trx.sh
# Describe:  monitor long transaction
# Revision:  1.0
# Date:    2019/09/16
# Author:   wang

/usr/local/mysql/bin/mysql -N -uroot -pxxxxxx -e "select now(),(UNIX_TIMESTAMP(now()) - UNIX_TIMESTAMP(a.trx_started)) diff_sec,b.id,b.user,b.host,b.db,d.SQL_TEXT from information_schema.innodb_trx a inner join
information_schema.PROCESSLIST b
on a.TRX_MYSQL_THREAD_ID=b.id and b.command = 'Sleep'
inner join performance_schema.threads c ON b.id = c.PROCESSLIST_ID
inner join performance_schema.events_statements_current d ON d.THREAD_ID = c.THREAD_ID;" | while read A B C D E F G H
do
 if [ "$C" -gt 30 ]
   then
   echo $(date +"%Y-%m-%d %H:%M:%S")
   echo "processid[$D] $E@$F in db[$G] hold transaction time $C SQL:$H"
 fi
done >> /tmp/longtransaction.txt

Brief description 1, here-gt 30 means 30 seconds, as long as it exceeds 30 seconds, it will be considered as a long transaction, which can be customized according to actual needs. This script can be executed by adding it to the timed task.

Summary:

This paper mainly introduces the long transaction related content, how to find long transactions, how to deal with long transactions, how to monitor long transactions. Maybe some friends don't understand much about affairs. I hope this article will be helpful to you. Because there are many query transaction related statements listed in this article, it is summarized as follows:


#  Query all running transactions and running time 
select t.*,to_seconds(now())-to_seconds(t.trx_started) idle_time from INFORMATION_SCHEMA.INNODB_TRX t \G

#  Query transaction details and executed SQL
select now(),(UNIX_TIMESTAMP(now()) - UNIX_TIMESTAMP(a.trx_started)) diff_sec,b.id,b.user,b.host,b.db,d.SQL_TEXT from information_schema.innodb_trx a inner join information_schema.PROCESSLIST b
on a.TRX_MYSQL_THREAD_ID=b.id and b.command = 'Sleep'
inner join performance_schema.threads c ON b.id = c.PROCESSLIST_ID
inner join performance_schema.events_statements_current d ON d.THREAD_ID = c.THREAD_ID;

#  Query all history of transaction execution SQL Record 
SELECT
 ps.id 'PROCESS ID',
 ps.USER,
 ps.HOST,
 esh.EVENT_ID,
 trx.trx_started,
 esh.event_name 'EVENT NAME',
 esh.sql_text 'SQL',
 ps.time 
FROM
 PERFORMANCE_SCHEMA.events_statements_history esh
 JOIN PERFORMANCE_SCHEMA.threads th ON esh.thread_id = th.thread_id
 JOIN information_schema.PROCESSLIST ps ON ps.id = th.processlist_id
 LEFT JOIN information_schema.innodb_trx trx ON trx.trx_mysql_thread_id = ps.id 
WHERE
 trx.trx_id IS NOT NULL 
 AND ps.USER != 'SYSTEM_USER' 
ORDER BY
 esh.EVENT_ID;
 
 #  Simple query transaction lock 
 select * from sys.innodb_lock_waits\G
 
 #  Query transaction lock details 
 SELECT
 tmp.*,
 c.SQL_Text blocking_sql_text,
 p.HOST blocking_host 
FROM
 (
 SELECT
  r.trx_state wating_trx_state,
  r.trx_id waiting_trx_id,
  r.trx_mysql_thread_Id waiting_thread,
  r.trx_query waiting_query,
  b.trx_state blocking_trx_state,
  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 
 ) tmp,
 information_schema.PROCESSLIST p,
 PERFORMANCE_SCHEMA.events_statements_current c,
 PERFORMANCE_SCHEMA.threads t 
WHERE
 tmp.blocking_thread = p.id 
 AND t.thread_id = c.THREAD_ID 
 AND t.PROCESSLIST_ID = p.id \G

Summarize


Related articles: