MySQL · 答疑解惑 · 備庫Seconds_Behind_Master計算

背景

在mysql主備環境下，主備同步過程如下，主庫更新產生binlog, 備庫io執行緒拉取主庫binlog生成relay log。備庫sql執行緒執行relay log從而保持和主庫同步。

理論上主庫有更新時，備庫都存在延遲，且延遲時間為備庫執行時間+網路傳輸時間即t4-t2。

那麼mysql是怎麼來計算備庫延遲的？

先來看show slave status中的一些資訊，io執行緒拉取主庫binlog的位置：

Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 107 

sql執行緒執行relay log的位置：

 Relay_Log_File: slave-relay.000003 Relay_Log_Pos: 253 

sql執行緒執行的relay log相對於主庫binlog的位置：

Relay_Master_Log_File: mysql-bin.000001 Exec_Master_Log_Pos: 107 

原始碼實現

Seconds_Behind_Master計算的原始碼實現如下：

if ((mi->get_master_log_pos() == mi->rli->get_group_master_log_pos()) &&
    (!strcmp(mi->get_master_log_name(), mi->rli->get_group_master_log_name())))
{ if (mi->slave_running == MYSQL_SLAVE_RUN_CONNECT)
    protocol->store(0LL); else protocol->store_null();
} else {
  long time_diff= ((long)(time(0) - mi->rli->last_master_timestamp)
                   - mi->clock_diff_with_master);

  protocol->store((longlong)(mi->rli->last_master_timestamp ? max(0L, time_diff) : 0));
} 

大致可以看出是透過時間和位點來計算的，下面詳細分析下。

if裡面條件表示如果io執行緒拉取主庫binlog的位置和sql執行緒執行的relay log相對於主庫binlog的位置相等，那麼認為延遲為0。一般情況下，io執行緒比sql執行緒快。但如果網路狀況特別差，導致sql執行緒需等待io執行緒的情況，那麼這兩個位點可能相等，會導致誤認為延遲為0。

再看else裡：

• clock_diff_with_master
  io執行緒啟動時會向主庫傳送sql語句“SELECT UNIX_TIMESTAMP()”，獲取主庫當前時間，然而用備庫當前時間減去此時間或者主備時間差值即為clock_diff_with_master。這裡如果有使用者中途修改了主庫系統時間或修改了timestamp變數，那麼計算出備庫延遲時間就是不準確的。

• last_master_timestamp
  表示主庫執行binlog事件的時間。此時間在並行複製和非並行複製時的計算方法是不同的

非並行複製：
備庫sql執行緒讀取了relay log中的event，event未執行之前就會更新last_master_timestamp，這裡時間的更新是以event為單位。

rli->last_master_timestamp= ev->when.tv_sec + (time_t) ev->exec_time; 

ev->when.tv_sec表示事件的開始時間。exec_time指事件在主庫的執行時間，只有Query_log_event和Load_log_event才會統計exec_time。
另外一種情況是sql執行緒在等待io執行緒獲取binlog時，會將last_master_timestamp設為0，按上面的演算法Seconds_Behind_Master為0，此時任務備庫是沒有延遲的。

並行複製：

並行複製有一個分發佇列gaq，sql執行緒將binlog事務讀取到gaq，然後再分發給worker執行緒執行。並行複製時，binlog事件是併發穿插執行的，gaq中有一個checkpoint點稱為lwm, lwm之前的binlog都已經執行，而lwm之後的binlog有些執行有些沒有執行。
假設worker執行緒數為2，gap有1,2,3,4,5,6,7,8個事務。worker 1已執行的事務為1 4 6, woker 2執行的事務為2 3 ，那麼lwm為4。

並行複製更新gap checkpiont時，會推進lwm點，同時更新last_master_timestamp為lwm所在事務結束的event的時間。因此，並行複製是在事務執行完成後才更新last_master_timestamp，更新是以事務為單位。同時更新gap checkpiont還受slave_checkpoint_period引數的影響。

這導致並行複製下和非並行複製統計延遲存在差距，差距可能為slave_checkpoint_period + 事務在備庫執行的時間。這就是為什麼在並行複製下有時候會有很小的延遲，而改為非並行複製時反而沒有延遲的原因。

另外當sql執行緒等待io執行緒時且gaq佇列為空時，會將last_master_timestamp設為0。同樣此時認為沒有延遲，計算得出seconds_Behind_Master為0。

位點資訊維護

• io執行緒拉取binlog的位點

  Master_Log_File 讀取到主庫ROTATE_EVENT時會更新(process_io_rotate) Read_Master_Log_Pos:io執行緒每取到一個event都會從event中讀取pos資訊並更新
  mi->set_master_log_pos(mi->get_master_log_pos() + inc_pos); 

• sql執行緒執行relay log的位置

  Relay_Log_File
    sql執行緒處理ROTATE_EVENT時更新(Rotate_log_event::do_update_pos)
  Relay_Log_Pos:
    非並行複製時，每個語句執行完成更新(stmt_done)
  並行複製時，事務完成時更新(Rotate_log_event::do_update_pos/ Xid_log_event::do_apply_event/stmt_done) 

• sql執行緒執行的relay log相對於主庫binlog的位置

  Relay_Master_Log_File
    sql執行緒處理ROTATE_EVENT時更新(Rotate_log_event::do_update_pos)
  Exec_Master_Log_Pos 和Relay_Log_Pos同時更新
    非並行複製時，每個語句執行完成更新(stmt_done)
    並行複製時，事務完成時更新(Rotate_log_event::do_update_pos/ Xid_log_event::do_apply_event/stmt_done) 

談到位點更新就有必要說到兩個事件：HEARTBEAT_LOG_EVENT 和 ROTATE_EVENT。

• HEARTBEAT_LOG_EVENT
  HEARTBEAT_LOG_EVENT我們的瞭解一般作用是，在主庫沒有更新的時候，每隔master_heartbeat_period時間都傳送此事件保持主庫與備庫的連線。而HEARTBEAT_LOG_EVENT另一個作用是，在gtid模式下，主庫有些gtid備庫已經執行同時，這些事件雖然不需要再備庫執行，但讀取和應用binglog的位點還是要推進。因此，這裡將這類event轉化為HEARTBEAT_LOG_EVENT，由HEARTBEAT_LOG_EVENT幫助我們推進位點。

• ROTATE_EVENT

  主庫binlog切換產生的ROTATE_EVENT，備庫io執行緒收到時會也有切換relay log。此rotate也會記入relay log，sql執行緒執行ROTATE_EVENT只更新位點資訊。備庫io執行緒接受主庫的HEARTBEAT_LOG_EVENT，一般不使用者處理。前面提到，gtid模式下，當HEARTBEAT_LOG_EVENT的位點大於當前記錄的位點時，會構建一個ROTATE_EVENT,從而讓sql執行緒推進位點資訊。

  if (mi->is_auto_position()  && mi->get_master_log_pos() < hb。log_pos
      &&  mi->get_master_log_name() != NULL)
  {
    mi->set_master_log_pos(hb。log_pos);
    write_ignored_events_info_to_relay_log(mi->info_thd, mi); //構建ROTATE_EVENT
    ......
  } 

另外，在replicate_same_server_id為0時，備庫接收到的binlog與主庫severid相同時，備庫會忽略此binlog，但位點仍然需要推進。為了效率，此binlog不需要記入relay log。而是替換為ROTATE_EVENT來推進位點。

延遲現象

初始主備是同步的，且沒有任何更新。假設主備庫執行某個DDL在都需要30s，執行某個大更新事務(例如insert..select * from )需要30s。

不考慮網路延遲。

• 非並行複製時

  執行DDL：t2時刻主庫執行完，t2時刻備庫執行show slave status，Seconds_Behind_Master值為0。同時t2至t3 Seconds_Behind_Master依次增大至30，然後跌0。

  執行大事務：t2時刻主庫執行完，t2時刻備庫執行show slave status，Seconds_Behind_Master值為30。同時t2至t3 Seconds_Behind_Master依次增大至60，然後跌0。

  以上區別的原因是exec_time只有Query_log_event和Load_log_event才會統計，普通更新沒有統計導致。

• 並行複製時

  執行DDL：t2時刻主庫執行完，t2至t3備庫執行show slave status，Seconds_Behind_Master值一直為0

  執行大事務：t2時刻主庫執行完，t2至t3備庫執行show slave status，Seconds_Behind_Master值一直為0

  這是因為執行語句之前主備是完全同步的，gaq佇列為空，會將last_master_timestamp設為0。而執行DDL過程中，gap checkpoint一直沒有推進，last_master_timestamp一直未0，直到DDL或大事務完成。
  所以t2至t3時刻Seconds_Behind_Master值一直為0。而t3時刻有一瞬間last_master_timestamp是會重置的，但又因slave_checkpoint_period會推進checkpoint,gaq佇列變為空，會將last_master_timestamp重設為0。
  因此t3時刻可能看到瞬間有延遲(對於DDL是延遲30s,對於大事務時延遲60s)。

  這似乎很不合理，gaq佇列為空，會將last_master_timestamp設為0,這條規則實際可以去掉。

相關bug

, PREVIOUS_GTIDS_LOG_EVENT 事件記錄在每個binlog的開頭，表示先前所有檔案的gtid集合。relay-log本身event記錄是主庫的時間，但relay log開頭的PREVIOUS_GTIDS_LOG_EVENT事件，是在slave端生成的，時間也是以slave為準的。因此不能用此時間計算last_master_timestamp。修復方法是在relay log寫PREVIOUS_GTIDS_LOG_EVENT事件是標記是relay log產生的，在統計last_master_timestamp時，發現是relay產生的事件則忽略統計。

if (is_relay_log)
  prev_gtids_ev。set_relay_log_event();
   ...... if (!(ev->is_artificial_event()||...))
   rli->last_master_timestamp= ev->when。tv_sec + (time_t) ev->exec_time; 

總結

Seconds_Behind_Master的計算並不準確和可靠。並行複製下Seconds_Behind_Master值比非並行複製時偏大。因此當我們判斷備庫是否延遲時，根據Seconds_Behind_Master=0不一定可靠。但是，當我們進行主備切換時，在主庫停寫的情況下，我們可以根據位點來判斷是否完全同步。

如果(Relay_Master_Log_File, Exec_Master_Log_Pos)和(Relay_Master_Log_File, Read_Master_Log_Pos)位置相等且Seconds_Behind_Master=0，那麼我們可以認為主備是完成同步的，可以進行切換。

轉自：