MySQL FAQ · Seconds_behind_master Calculation of Standby library

Background

In the MySQL master and standby environment, the main standby synchronization process is as follows, the main library update generates Binlog, the standby IO line pulls take the main library binlog generate relay log. The standby SQL thread executes the relay log to maintain synchronization with the main library.

In theory, when the main library is updated, there is a delay in the standby, and the delay time is the standby execution time + network transmission time is t4-t2.

So how does MySQL calculate the standby delay?

First take a look at some of the information in Show slave status, Io line pulls the location of the main library Binlog:

Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 107

The SQL thread executes the location of the relay log:

Relay_Log_File: slave-relay.000003 Relay_Log_Pos: 253

The relay log executed by the SQL thread is relative to the location of the main library Binlog:

Relay_Master_Log_File: mysql-bin.000001 Exec_Master_Log_Pos: 107

Source Code Implementation

Seconds_behind_master calculation of the source code implementation is as follows:

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)); }

It can be seen that it is calculated by time and place, under detailed analysis below.

The IF condition indicates that the delay is 0 if the IO line pulls takes the location of the main library binlog and the relay log executed by the SQL thread is equal to the location binlog the main library. In general, IO threads are faster than SQL threads. However, if the network condition is particularly poor, causing the SQL thread to wait for the IO thread, the two bits may be equal, leading to a false-thinking delay of 0.

Look in Else:

• clock_diff_with_master
  When the IO thread starts, the SQL statement "select Unix_timestamp ()" is sent to the main library to obtain the current time of the main library, minus this time with the current time of the repository, or the primary and standby difference value clock_diff_with_master . If there are users who have modified the main library system time or modified the timestamp variable halfway, then calculating the standby delay time is inaccurate.

• last_master_timestamp
  Represents the time at which the main library executes the Binlog event. This time is calculated differently in parallel and non-parallel replication

Non-parallel replication:
The standby SQL thread reads the event,event in relay log is not executed before it is updated last_master_timestamp , where the time is updated in the event unit.

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

Ev->when.tv_sec represents the start time of the event. Exec_time refers to the event in the main library execution time, only Query_log_event and Load_log_event will be counted exec_time.
Another case is that when the SQL thread waits for the IO thread to get binlog, it will be last_master_timestamp set to 0 and seconds_behind_master to 0 for the above algorithm, at which time there is no delay in the task repository.

Parallel replication:

Parallel replication has a distribution queue Gaq,sql thread reads the Binlog transaction to GAQ and then distributes it to the worker thread for execution. In parallel replication, the Binlog event is executed concurrently, and there is a checkpoint point in Gaq called Lwm, and LWM before Binlog has been executed, and lwm some executions after binlog have not been executed.
Assume that the number of worker threads is 2,gap with 1,2,3,4,5,6,7,8 transactions. Worker 1 has performed a transaction of 1 4 6, Woker 2 performs a transaction of 2 3, then LWM is 4.

When you update gap Checkpiont in parallel replication, the lwm point is pushed, and the time of the event that the last_master_timestamp LWM transaction ends is updated. Therefore, parallel replication is updated after the transaction execution is complete last_master_timestamp , and the update is in the transaction unit. At the same time, updating Gap Checkpiont is also affected by slave_checkpoint_period the parameters.

This results in a gap between parallel replication and non-parallel replication statistics latency, which may be the slave_checkpoint_period time the + transaction executes in the standby. This is why there are sometimes very small delays under parallel replication, and there is no delay in changing to non-parallel replication.

In addition, when the SQL thread waits for an IO thread and the gaq queue is empty, it will be last_master_timestamp set to 0. Also at this time there is no delay, calculated seconds_Behind_Master as 0.

Site-Information Maintenance

• Io line pulls take 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 thread execution Relay Log location

   relay_log_file SQL thread processing rotate_event when updating (rotate_log_event::do_update_pos) Relay_log_pos: Non-parallel replication, each statement performs a complete update (stmt _done) in parallel replication, the transaction completes when the update (Rotate_log_event:: do_update_pos/xid_log_event:: do_apply_event/stmt_done)       

• The location of the relay log executed by the SQL thread relative to the main library 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)

When it comes to site updates, it's worth mentioning two events: Heartbeat_log_event and Rotate_event.

• Heartbeat_log_event
  Heartbeat_log_event The general purpose of our understanding is that when the main library is not updated, master_heartbeat_period This event is sent every time to keep the main library connected to the standby. Another effect of heartbeat_log_event is that, in Gtid mode, some gtid repositories of the main library have been executed, and although these events do not need to be re-prepared, the bits of the binglog are read and applied to advance. So, this kind of EVENT is translated into heartbeat_log_event, and Heartbeat_log_event helps us to push the site.

• Rotate_event

  Main Library Binlog switch generated rotate_event, the standby IO thread will also have to switch relay log when it is received. This rotate is also credited to relay Log,sql thread execution rotate_event only update bit information. The Standby IO thread accepts the heartbeat_log_event of the main library and is generally not handled by the user. As mentioned earlier, in Gtid mode, when the heartbeat_log_event bit is larger than the current record's bit, a rotate_event is built, allowing the SQL thread to push the bit information.

   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);//Build rotate_event ...}  

Also, at replicate_same_server_id 0 o'clock, when the Binlog received by the repository is Severid with the main library, the repository ignores this binlog, but the bit points still need to be advanced. For efficiency, this binlog does not need to be recorded in relay log. Instead, replace it with Rotate_event to push the site.

Delay phenomenon

The initial master is synchronized and there are no updates. Assuming that the Master repository executes a DDL that requires 30s, perform a large update transaction (for example, insert: SELECT * from) requires 30s.

Network latency is not considered.

• When non-parallel replication

  Execution Ddl:t2 time the main library execution, T2 time to prepare the library execution show slave status,seconds_behind_master value is 0. At the same time T2 to T3 Seconds_behind_master increased to 30, then down 0.

  Perform large transactions: T2 time the main library execution, T2 time to prepare the library execution show slave status,seconds_behind_master value of 30. At the same time T2 to T3 Seconds_behind_master increased to 60, then down 0.

  The reason for the difference is that exec_time only Query_log_event and only Load_log_event statistics, the normal update is not statistically caused.

• When parallel replication

  Execution ddl:t2 at the end of the main library execution, T2 to T3 prepare the show slave status,seconds_behind_master value has been 0

  Perform large transaction: T2 time the main library executes, T2 to T3 the show slave status,seconds_behind_master value has been 0

  This is because the main preparation is fully synchronized before executing the statement, and the gaq queue is empty and will be last_master_timestamp set to 0. In the execution of the DDL process, Gap checkpoint has not been advanced, last_master_timestamp has not been 0 until the DDL or large transaction completed.
  So the T2 to T3 time Seconds_behind_master value has been 0. The T3 moment is reset last_master_timestamp , but because slave_checkpoint_period it pushes the checkpoint,gaq queue to empty, it last_master_timestamp resets to 0.
  So the T3 moment may see a momentary delay (for DDL is 30s delay, 60s for large transactions).

  This seems unreasonable, gaq queue is empty, will be last_master_timestamp set to 0, this rule can actually be removed.

Related bugs

bug#72376, the Previous_gtids_log_event event is recorded at the beginning of each binlog, representing the Gtid collection of all previous files. Relay-log itself the event record is the time of the main library, but the Previous_gtids_log_event event at the beginning of relay LOG is generated on the slave side and the time is slave. Therefore, this time cannot be calculated last_master_timestamp . The fix is to write the Previous_gtids_log_event event in relay log that the token is relay log, and in the statistics last_master_timestamp , the event that is relay generated is ignored.

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;

Summarize

The calculation of Seconds_behind_master is not accurate and reliable. The Seconds_behind_master value under parallel replication is larger than non-parallel replication. Therefore, when we determine whether the standby is delayed, it is not necessarily reliable according to Seconds_behind_master=0. However, when we switch between primary and standby, when the main library is stopped writing, we can determine whether the full synchronization is based on the bit point.

if (Relay_master_log_file, Exec_master_log_pos) and (Relay_master_log_file, read_master_log_pos) have equal positions and seconds_behind_ Master=0, then we can assume that the main preparation is complete synchronization and can be switched.

Transferred from: http://mysql.taobao.org/monthly/2016/03/09/

MySQL FAQ · Seconds_behind_master Calculation of Standby library