Description:
When I was executing a stress test script, I found the following situation: when concurrent optimize operations were performed on the same table, show processlist was performed on the replica, and the results were as follows:
mysql> show processlist;
+----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+
| 6 | system user | connecting host | NULL | Connect | 3413 | Waiting for source to send event | NULL |
| 7 | system user | | NULL | Query | 0 | Waiting for dependent transaction to commit | NULL |
| 8 | system user | | | Query | 206 | altering table | optimize table t1.t1 |
| 9 | system user | | NULL | Query | 2685 | Waiting for an event from Coordinator | NULL |
| 10 | event_scheduler | localhost | NULL | Daemon | 3413 | Waiting on empty queue | NULL |
| 19 | root | localhost:37814 | NULL | Query | 0 | init | show processlist |
+----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+
6 rows in set (0.00 sec)
mysql> show processlist;
+----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+
| 6 | system user | connecting host | NULL | Connect | 3414 | Waiting for source to send event | NULL |
| 7 | system user | | NULL | Query | 0 | Waiting for dependent transaction to commit | NULL |
| 8 | system user | | | Query | 205 | preparing for alter table | optimize table t1.t1 |
| 9 | system user | | NULL | Query | 2686 | Waiting for an event from Coordinator | NULL |
| 10 | event_scheduler | localhost | NULL | Daemon | 3414 | Waiting on empty queue | NULL |
| 19 | root | localhost:37814 | NULL | Query | 0 | init | show processlist |
+----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+
6 rows in set (0.00 sec)
You can see that the Time field of thread 8 is gradually accumulating. I used MTS, and thread 8 is a worker thread. This table is very small, so optimize executes very quickly. So the Time field is incorrect.
I also parsed the relay log and observed iimmediate_commit_timestamp, and also found that the optimize operation is executed quickly. So the Time field is incorrect.
#241011 10:39:51 server id 1 end_log_pos 645103 CRC32 0xaf202a0a GTID last_committed=2527 sequence_number=2528 rbr_only=no original_committed_timestamp=1728614496874256 immediate_commit_timestamp=1728614496874256 transaction_length=168
SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2528'/*!*/;
#241011 10:39:51 server id 1 end_log_pos 645271 CRC32 0xde9dfa05 GTID last_committed=2528 sequence_number=2529 rbr_only=no original_committed_timestamp=1728614496882281 immediate_commit_timestamp=1728614496882281 transaction_length=168
SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2529'/*!*/;
#241011 10:39:51 server id 1 end_log_pos 645439 CRC32 0x1a5ea965 GTID last_committed=2529 sequence_number=2530 rbr_only=no original_committed_timestamp=1728614496889577 immediate_commit_timestamp=1728614496889577 transaction_length=168
SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2530'/*!*/;
#241011 10:39:53 server id 1 end_log_pos 645607 CRC32 0x357e3592 GTID last_committed=2530 sequence_number=2531 rbr_only=no original_committed_timestamp=1728614497743396 immediate_commit_timestamp=1728614497743396 transaction_length=168
SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2531'/*!*/;
#241011 10:39:53 server id 1 end_log_pos 645775 CRC32 0x6176238c GTID last_committed=2531 sequence_number=2532 rbr_only=no original_committed_timestamp=1728614498619659 immediate_commit_timestamp=1728614498619659 transaction_length=168
SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2532'/*!*/;
How to repeat:
Use MTS.
You can execute the following script:
#! /bin/bash
MYSQL="mysql -P4532 -h127.0.0.1 -uroot"
$MYSQL -e "create database tt" &
wait
$MYSQL -e " create table tt.t1(a int AUTO_INCREMENT, b int, PRIMARY KEY (a), UNIQUE KEY (b))" &
wait
for((i=1;i<=1000;i++));
do
$MYSQL -e "insert into tt.t1(b) values (${i})" &
wait
done
for((i=1;i<=1000;i++));
do
$MYSQL -e "optimize table tt.t1" &
done
============================
Execute show processlist continuously on the replica.
Description: When I was executing a stress test script, I found the following situation: when concurrent optimize operations were performed on the same table, show processlist was performed on the replica, and the results were as follows: mysql> show processlist; +----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+ | 6 | system user | connecting host | NULL | Connect | 3413 | Waiting for source to send event | NULL | | 7 | system user | | NULL | Query | 0 | Waiting for dependent transaction to commit | NULL | | 8 | system user | | | Query | 206 | altering table | optimize table t1.t1 | | 9 | system user | | NULL | Query | 2685 | Waiting for an event from Coordinator | NULL | | 10 | event_scheduler | localhost | NULL | Daemon | 3413 | Waiting on empty queue | NULL | | 19 | root | localhost:37814 | NULL | Query | 0 | init | show processlist | +----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+ 6 rows in set (0.00 sec) mysql> show processlist; +----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+ | 6 | system user | connecting host | NULL | Connect | 3414 | Waiting for source to send event | NULL | | 7 | system user | | NULL | Query | 0 | Waiting for dependent transaction to commit | NULL | | 8 | system user | | | Query | 205 | preparing for alter table | optimize table t1.t1 | | 9 | system user | | NULL | Query | 2686 | Waiting for an event from Coordinator | NULL | | 10 | event_scheduler | localhost | NULL | Daemon | 3414 | Waiting on empty queue | NULL | | 19 | root | localhost:37814 | NULL | Query | 0 | init | show processlist | +----+-----------------+-----------------+------+---------+------+---------------------------------------------+----------------------+ 6 rows in set (0.00 sec) You can see that the Time field of thread 8 is gradually accumulating. I used MTS, and thread 8 is a worker thread. This table is very small, so optimize executes very quickly. So the Time field is incorrect. I also parsed the relay log and observed iimmediate_commit_timestamp, and also found that the optimize operation is executed quickly. So the Time field is incorrect. #241011 10:39:51 server id 1 end_log_pos 645103 CRC32 0xaf202a0a GTID last_committed=2527 sequence_number=2528 rbr_only=no original_committed_timestamp=1728614496874256 immediate_commit_timestamp=1728614496874256 transaction_length=168 SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2528'/*!*/; #241011 10:39:51 server id 1 end_log_pos 645271 CRC32 0xde9dfa05 GTID last_committed=2528 sequence_number=2529 rbr_only=no original_committed_timestamp=1728614496882281 immediate_commit_timestamp=1728614496882281 transaction_length=168 SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2529'/*!*/; #241011 10:39:51 server id 1 end_log_pos 645439 CRC32 0x1a5ea965 GTID last_committed=2529 sequence_number=2530 rbr_only=no original_committed_timestamp=1728614496889577 immediate_commit_timestamp=1728614496889577 transaction_length=168 SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2530'/*!*/; #241011 10:39:53 server id 1 end_log_pos 645607 CRC32 0x357e3592 GTID last_committed=2530 sequence_number=2531 rbr_only=no original_committed_timestamp=1728614497743396 immediate_commit_timestamp=1728614497743396 transaction_length=168 SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2531'/*!*/; #241011 10:39:53 server id 1 end_log_pos 645775 CRC32 0x6176238c GTID last_committed=2531 sequence_number=2532 rbr_only=no original_committed_timestamp=1728614498619659 immediate_commit_timestamp=1728614498619659 transaction_length=168 SET @@SESSION.GTID_NEXT= '6bb18586-798d-11ef-b2df-b8599f3009a8:2532'/*!*/; How to repeat: Use MTS. You can execute the following script: #! /bin/bash MYSQL="mysql -P4532 -h127.0.0.1 -uroot" $MYSQL -e "create database tt" & wait $MYSQL -e " create table tt.t1(a int AUTO_INCREMENT, b int, PRIMARY KEY (a), UNIQUE KEY (b))" & wait for((i=1;i<=1000;i++)); do $MYSQL -e "insert into tt.t1(b) values (${i})" & wait done for((i=1;i<=1000;i++)); do $MYSQL -e "optimize table tt.t1" & done ============================ Execute show processlist continuously on the replica.