type
status
date
slug
summary
tags
category
icon
password
Made by Johnson
前言
在 MySQL 8.0 之前只能從 SHOW SLAVE STATUS 中的 Second_Behind_Master 來確認 replication delay，但是這對於複雜的 replication topologies (拓撲) 不適用，例如：
如上圖，在 8.0 之前我們在 C 的機器只能知道 B、C 之間的 replication delay，無法知道 A、C 之間的 replication delay，而 MySQL 8.0 進行了一些改善。
Replication Delay Timestamps
MySQL 8.0 開始提供了新的方式來測量 replication delay，方法是在 binlog 中為 Transaction 添加以下兩個時間戳：
- original_commit_timestamp：紀錄 Transaction 在最原本的 Master commit 的時間戳
- immediate_commit_timestamp：紀錄 Transaction 在 Slave 連線的 Master 上 commit 的時間戳
透過 mysqlbinlog 指令查看 MySQL 8.0 之後的 binlog：
- 在所有的 Replica 中，所有被回放的 Transaction 其 original_commit_timestamp 始終相同，都是最源頭的 Source 執行該 Query 時 commit 的時間。
- 在源頭的 Source binlog 中 original_commit_timestamp 等於 immediate_commit_timestamp。
- 在 Replica 的 relay log 中其 original_commit_timestamp 、immediate_commit_timestamp 會等於其連線 Source 上的 binlog 紀錄。
- 在 Replica 的 binlog 中，immediate_commit_timestamp 是自己 commit 的時間戳。
Monitoring Replication Delay
除了添加了新的 replication delay timestamp，8.0 也在 performance_schema 中新增以下三張表方便觀察 replication delay：
replication_connection_status：紀錄 IO_THREAD 在寫入 relay log 的工作狀態。
- LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP
最後一個已寫入 relay log 的 Transaction 其 original_commit_timestamp。
- LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP 最後一個已寫入 relay log 的 Transaction 其 immediate_commit_timestamp。
- LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP 最後一個已寫入 relay log 的 Transaction 的開始時間。
- LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP 最後一個已寫入 relay log 的 Transaction 的結束時間。
- QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP 正在寫入 relay log 的 Transaction 其 original_commit_timestamp。
- QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP 正在寫入 relay log 的 Transaction 其 immediate_commit_timestamp。
- QUEUEING_TRANSACTION_START_QUEUE_TIMESTAMP 正在寫入 relay log 的 Transaction 其開始寫入的時間。
replication_applier_status_by_worker：記錄每一條 SQL_THREAD 的工作狀態。
- LAST_APPLIED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP 最後一個被回放的 Transaction 其 original_commit_timestamp。
- LAST_APPLIED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP 最後一個被回放的 Transaction 其 immediate_commit_timestamp。
- LAST_APPLIED_TRANSACTION_START_APPLY_TIMESTAMP 最後一個被回放的 Transaction 其回放的開始時間。
- LAST_APPLIED_TRANSACTION_END_APPLY_TIMESTAMP 最後一個被回放的 Transaction 其回放的結束時間。
- APPLYING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP 正在被回放的 Transaction 其 original_commit_timestamp。
- APPLYING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP 正在被回放的 Transaction 其 immediate_commit_timestamp。
- APPLYING_TRANSACTION_START_APPLY_TIMESTAMP 正在被回放的 Transaction 其回放的開始時間。
replication_applier_status_by_coordinator：紀錄 MTS 中的 Coordinator 線程的工作狀態，當未開啟 MTS 此表為空。
- LAST_PROCESSED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP 最後一個被 Coordinator 線程處理的 Transaction 其 original_commit_timestamp。
- LAST_PROCESSED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP 最後一個被 Coordinator 線程處理的 Transaction 其 immediate_commit_timestamp。
- LAST_PROCESSED_TRANSACTION_START_BUFFER_TIMESTAMP 最後一個 Transaction 什麼時候開始被 Coordinator 寫入 Worker 線程的 buffer。
- LAST_PROCESSED_TRANSACTION_END_BUFFER_TIMESTAMP
最後一個 Transaction 什麼時候被 Coordinator 寫入 Worker 線程的 buffer。
- PROCESSING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP
正在被 Coordinator 線程處理的 Transaction 其 original_commit_timestamp。
- PROCESSING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP 正在被 Coordinator 線程處理的 Transaction 其 immediate_commit_timestamp。
- PROCESSING_TRANSACTION_START_BUFFER_TIMESTAMP
正在被 Coordinator 線程處理的 Transaction 其開始寫入 Worker 線程的 buffer 的時間。
注意：這些 Table 中的 immediate_commit_timestamp 都是從
relay log 中取得。範例
- 觀察 A → C 之間完整的延遲
- 觀察 B → C 之間完整的延遲
- C 正在回放的 Transaction 和 B 的延遲
- 開啟 MTS 時，Coordinator 正在處理的 Transaction 和 B 的延遲
- 觀察 C relaylog 中最後寫入的 Transaction 在 A commit 的延遲
- 觀察 B → C 之間 relaylog 的寫入延遲
其他用途
在 binlog 中我們知道有 exec_time 這個值，但這個值並不能讓我們準確的知道 Transaction commit 的確切時間，但在 MySQL 8.0 之後我們可以透過觀測 original_commit_timestamp 來確認，參考以下例子：在一張表上執行了 458752 筆資料的 update，總計花費時間 13.62 sec
讓我們看一下 binlog：
可以看到 exec_time 顯示的是 1，而不是正確的執行時間，這是因為 exec_time 指的是 update 第一筆資料花費的時間，而不是整個 update 語句執行的時間。
不過從 MySQL 8.0 開始我們就可以透過 transaction 開始時間 (也就是 16:55:06) 和 transaction commit 的時間 - immediate_commit_timestamp (也就是 16:55:19) 判斷出這個 transaction 執行了 13 sec。