[MySQL] MySQL 发生同步延迟时Seconds_Behind_Master还为0的原因

./sql/rpl_slave.cc
 
bool show_slave_status_send_data(THD *thd, Master_info *mi,
                 char* io_gtid_set_buffer,
                 char* sql_gtid_set_buffer)
......
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));
  }
......

/*
   The pseudo code to compute Seconds_Behind_Master:
   if (SQL thread is running)
   {
   if (SQL thread processed all the available relay log)
   {
     if (IO thread is running)
      print 0;
     else
      print NULL;
   }
    else
    compute Seconds_Behind_Master;
  }
  else
   print NULL;
*/

• SQL 线程正常，且回放完所有的 relaylog 时，如果 IO 线程正常，那么直接置 0。
  
• SQL 线程正常，且回放完所有的 relaylog 时，如果 IO 线程不正常，那么直接置 NULL。
  
• SQL 线程正常，且没有回放完所有的 relaylog 时，计算延迟时间。
  

• time(0)：当前的时间戳，timestamp 格式的。
  
• last_master_timestamp：这个 event 在主库上执行的时刻，timestamp 格式。
  
• clock_diff_with_master：slave 和 master 的时间差，在 IO 线程启动时获取的。
  

./sql/rpl_slave.cc
 
......
  if (ev)
  {
  enum enum_slave_apply_event_and_update_pos_retval exec_res;
 
  ptr_ev= &ev;
  /*
    Even if we don't execute this event, we keep the master timestamp,
    so that seconds behind master shows correct delta (there are events
    that are not replayed, so we keep falling behind).
 
    If it is an artificial event, or a relay log event (IO thread generated
    event) or ev->when is set to 0, or a FD from master, or a heartbeat
    event with server_id '0' then  we don't update the last_master_timestamp.
 
    In case of parallel execution last_master_timestamp is only updated when
    a job is taken out of GAQ. Thus when last_master_timestamp is 0 (which
    indicates that GAQ is empty, all slave workers are waiting for events from
    the Coordinator), we need to initialize it with a timestamp from the first
    event to be executed in parallel.
  */
  if ((!rli->is_parallel_exec() || rli->last_master_timestamp == 0) &&
     !(ev->is_artificial_event() || ev->is_relay_log_event() ||
      (ev->common_header->when.tv_sec == 0) ||
      ev->get_type_code() == binary_log::FORMAT_DESCRIPTION_EVENT ||
      ev->server_id == 0))
  {
    rli->last_master_timestamp= ev->common_header->when.tv_sec +
                  (time_t) ev->exec_time;
    DBUG_ASSERT(rli->last_master_timestamp >= 0);
  }
......

./sql/rpl\_slave.cc
 
......
  /*
  We need to ensure that this is never called at this point when
  cnt is zero. This value means that the checkpoint information
  will be completely reset.
  */
 
  /*
  Update the rli->last_master_timestamp for reporting correct Seconds_behind_master.
 
  If GAQ is empty, set it to zero.
  Else, update it with the timestamp of the first job of the Slave_job_queue
  which was assigned in the Log_event::get_slave_worker() function.
  */
  ts= rli->gaq->empty()
  ? 0
  : reinterpret_cast<Slave_job_group*>(rli->gaq->head_queue())->ts;
  rli->reset_notified_checkpoint(cnt, ts, need_data_lock, true);
  /* end-of "Coordinator::"commit_positions" */
 
......

/*
  Currently, the checkpoint routine is being called by the SQL Thread.
  For that reason, this function is called call from appropriate points
  in the SQL Thread's execution path and the elapsed time is calculated
  here to check if it is time to execute it.
*/
set_timespec_nsec(&curr_clock, 0);
ulonglong diff= diff_timespec(&curr_clock, &rli->last_clock);
if (!force && diff < period)
{
  /*
  We do not need to execute the checkpoint now because
  the time elapsed is not enough.
  */
  DBUG_RETURN(FALSE);
}

• 开启并行复制之后，延迟时间会经常性的在 0 和 1 之间跳变。
  
• alter 操作，单个大事务等在并行复制的场景下容易导致延迟时间不准，而普通的复制方式不会。
  
• 由于主从时间差是在 IO 线程启动时就计算好的，所以期间 slave 的时间出现偏差之后，延迟时间也会出现偏差。