Apakah perbezaan antara komit lambat dalam pertanyaan lambat MySQL dan transaksi lambat dalam binlog?

1. Sumber masalah

Pertanyaan perlahan dan transaksi perlahan binlog adalah kaedah yang biasa digunakan semasa menganalisis masalah prestasi. Baru-baru ini, saya sedang menganalisis pertanyaan yang perlahan dan mendapati bahawa ia mengandungi sejumlah besar pernyataan komit yang perlahan, tetapi pemadanan tidak dapat diselesaikan apabila menganalisis urus niaga perlahan binlog. Sebagai contoh, mungkin terdapat 1,000 penyata komit dalam tempoh ini, tetapi mungkin terdapat hanya 100 urus niaga yang perlahan Ini terlalu berbeza. Jadi mengapa fenomena ini berlaku?

2. Kaedah penghakiman masing-masing

• Transaksi perlahan biasanya seperti berikut untuk transaksi (sisipan) secara eksplisit:

• GTID_LOG_EVENT dan XID_EVENT ialah masa apabila arahan "COMMIT" dimulakan.

• Kali pertama arahan "INSERT" dimulakan ialah QUERY_EVENT.

• MAP_EVENT/WRITE_ROWS_EVENT ialah masa apabila setiap perintah ‘Sisipkan’

Jadi kita biasanya mendapat masa transaksi yang perlahan dengan menolak masa QUERY_EVENT daripada masa XID_EVENT Sudah tentu, jika ia diserahkan secara automatik, ia tidak boleh dikira seperti ini kerana Setiap peristiwa adalah masa apabila penyataan dimulakan.

• Kemungkinan komit perlahan

Kami tahu bahawa tempat yang paling mungkin untuk komit perlahan adalah dalam pembilasan binlog atau menunggu ACK budak separa segerak Walau bagaimanapun, masa XID EVENT dalam binlog tidak termasuk bahagian masa ini, yang bermaksud rekod komit dalam transaksi perlahan binlog dan pertanyaan lambat tidak berada dalam tempoh masa yang sama.

• Penjelasan ringkas

Jika kita mengambil transaksi berikut sebagai contoh, berikan penjelasan ringkas

begin;
insert into it values(10);
commit;        
-- insert语句执行      -> QUERY_EVENT时间(T1)  
-- insert语句执行完成,判定insert语句是否为慢查询(T2)          
-- commit语句执行      -> GTID_LOG_EVENT和XID_EVENT时间(T3)
   flush
   fsync
                  -----> 传输binlog (sync_binlog=1)
                  <----   等待ACK   (rpl_semi_sync_master_wait_point=AFTER_SYNC)
   commit
-- commit语句执行完成,判定commit语句是否为慢查询(T4)

• Kriteria untuk menilai sama ada pernyataan sisipan lambat ialah T2-T1 (-masa kunci)

• Kriteria untuk menilai sama ada pernyataan komit lambat ialah T4-T3

• Standard untuk menentukan urus niaga lambat ialah T3-T1

Oleh itu, hampir tiada pertindihan antara penentuan urus niaga lambat dan penentuan lambat melakukan dalam pertanyaan perlahan, jadi adalah perkara biasa untuk situasi ini berlaku, seperti berikut untuk membuktikan.

3. Bukti

• Pustaka utama: Tamat masa separa penyegerakan ialah 999999999.

• Pustaka hamba: Tetapkan sync_relay_log=1, dan tetapkan titik putus pada fungsi MYSQL_BIN_LOG::flush_and_sync Fungsi ini dipengaruhi oleh sync_relay_log=1 selepas setiap peristiwa ditulis ke log geganti perpustakaan.Menjejaskan fungsi keputusan yang mesti diletakkan di pasaran.

Dengan cara ini, secara artifisial menunggu di titik putus akan memanjangkan masa komit dengan ketara Ia juga membuktikan bahawa separuh penyegerakan yang perlahan akan menjejaskan komit perlahan, seperti berikut:

begin;
select now();   -T1
insert into it values(10);
select sleep(10);
select now();   -T2
commit; (断点在从库生效卡主ack) -T3
select now();   -T4

结果
mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> select now();      -T1
+---------------------+
| now()               |
+---------------------+
| 2022-06-12 22:20:43 |
+---------------------+
1 row in set (0.00 sec)

mysql> insert into it values(10);
Query OK, 1 row affected (0.10 sec)

mysql> select sleep(10);

+-----------+
| sleep(10) |
+-----------+
|         0 |
+-----------+
1 row in set (10.01 sec)

mysql> select now();      -T2 AND T3
+---------------------+
| now()               |
+---------------------+
| 2022-06-12 22:20:54 |
+---------------------+
1 row in set (0.00 sec)

mysql> commit;         
Query OK, 0 rows affected (21.64 sec)

mysql> select now();    -T4
+---------------------+
| now()               |
+---------------------+
| 2022-06-12 22:21:15 |
+---------------------+
1 row in set (0.00 sec)

.

Mari analisa pertanyaan perlahan dan binlog Penambahan sleep(10) memanjangkan masa komitmen transaksi kerana sisipan terlalu pantas.

• transaksi perlahan binlog 22:20:54(T2) - 22:20:43(T1) = kira-kira 11 saat (kami menambah tidur(10))

# at 12221
#220612 22:20:54 server id 613306  end_log_pos 12286 CRC32 0x3e019332   GTID    last_committed=40       sequence_number=41      rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= '00320cc8-39f9-11ec-b5ba-000c2929706d:41'/*!*/;
# at 12286
#220612 22:20:43 server id 613306  end_log_pos 12360 CRC32 0x8dcde193   Query   thread_id=43    exec_time=1     error_code=0
SET TIMESTAMP=1655043643/*!*/;
BEGIN
/*!*/;
# at 12360
#220612 22:20:43 server id 613306  end_log_pos 12409 CRC32 0x0db68582   Rows_query
# insert into it values(10)
# at 12409
#220612 22:20:43 server id 613306  end_log_pos 12456 CRC32 0x363a48c7   Table_map: `mysemi`.`it` mapped to number 124
# at 12456
#220612 22:20:43 server id 613306  end_log_pos 12496 CRC32 0xd44e43f3   Write_rows: table id 124 flags: STMT_END_F
### INSERT INTO `mysemi`.`it`
### SET
###   @1=10 /* INT meta=0 nullable=1 is_null=0 */
# at 12496
#220612 22:20:54 server id 613306  end_log_pos 12527 CRC32 0x4d8d2c64   Xid = 547
COMMIT/*!*/;

• Komit dalam pertanyaan perlahan ialah 22:21:15(T4) - 22:20:54(T3) = 21 saat

# Time: 2022-06-12T22:21:15.746223Z
# User@Host: root[root] @ localhost []  Id:    43
# Schema: mysemi  Last_errno: 0  Killed: 0
# Query_time: 21.641090  Lock_time: 0.000000  Rows_sent: 0  Rows_examined: 0  Rows_affected: 0
# Bytes_sent: 11
SET timestamp=1655043675;
commit;

Adalah jelas di sini bahawa komit perlahan rekod pertanyaan lambat jelas tidak termasuk dalam transaksi perlahan.

Atas ialah kandungan terperinci Apakah perbezaan antara komit lambat dalam pertanyaan lambat MySQL dan transaksi lambat dalam binlog?. Untuk maklumat lanjut, sila ikut artikel berkaitan lain di laman web China PHP!