为什么在MySQL双主单写的情况下主库偶尔出现大量延缓

发布时间：2022-01-17 13:14 所属栏目：115 来源：互联网

导读：为什么在MySQL双主单写的情况下主库偶尔出现大量延迟，相信很多没有经验的人对此束手无策，为此本文总结了问题出现的原因和解决方法，通过这篇文章希望你能解决这个问题。我们是双主单写，这里约定写入的库为主库，没有写入的库为从库。我们的falcon偶尔会

为什么在MySQL双主单写的情况下主库偶尔出现大量延迟，相信很多没有经验的人对此束手无策，为此本文总结了问题出现的原因和解决方法，通过这篇文章希望你能解决这个问题。

我们是双主单写，这里约定写入的库为主库，没有写入的库为从库。我们的falcon偶尔会进行报警如下（频率很低）：

这是非常奇怪的，按理说我是单写的从库没有做任何操作（除了应用Event以外），主库哪来的延迟，并且延迟这么大。在我映像中有朋友问过这个问题，当时没有细细研究。

二、延迟计算的规则
我们还是要看看主从计算延迟的伪代码：

/*
     The pseudo code to compute Seconds_Behind_Master:
     if (SQL thread is running)
//如果SQL线程启动了
     {
       if (SQL thread processed all the available relay log)
//如果SQL线程已经应用完了所有的IO线程写入的Event
       {
         if (IO thread is running)
//如果IO线程启动了
            print 0;
//设置延迟为0
         else
            print NULL;
//否则为空值
       }
        else
          compute Seconds_Behind_Master;
//如果SQL线程没有应用完所有的IO线程写入的Event，那么需要计算延迟。
      }
      else
       print NULL;
//如果连SQL线程也没有启动则设置为空值
  */
计算延迟的公式为：

long time_diff= ((long)(time(0)
                          - mi->rli->last_master_timestamp)
                          - mi->clock_diff_with_master);
也就是：
服务器当前时间-Event header中的timestamp - 主从服务器时间差
出现延迟的必要条件：

如果SQL线程没有应用完了所有的IO线程写入的Event，也就是Read_Master_Log_Pos和Exec_Master_Log_Pos存在一定的差值。判定标准为
(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()))
抛开文件名，也就是通过 IO线程读取到主库binary log的位置和 SQL线程应用到的主库binary log位置进行比较来进行判断，只要他们出现差值就会进入延迟计算环节。
服务器当前时间-Event header中的timestamp - 主从服务器时间差这个公式必须出现差值。
好了接下来带着这两个产生延迟的必要条件来寻求原因。

三、产生延迟的原因
1.主库：首先主库写到从库的Event，从库会写入到binlog（log_slave_updates 开启），并且从库的DUMP线程会发送给主库，但是主库的IO线程通过SERVER_ID进程判定，将Event进行过滤，不写入主库的relay log，同时会更新主库IO线程读取的位置（Read_Master_Log_Pos），并且更新忽略到的位置（rli->ign_master_log_name_end[0]）。代码如下：

    if (!(s_id == ::server_id && !mi->rli->replicate_same_server_id) ||
        (event_type != binary_log::FORMAT_DESCRIPTION_EVENT &&
         event_type != binary_log::ROTATE_EVENT &&
         event_type != binary_log::STOP_EVENT))
    {
      mi->set_master_log_pos(mi->get_master_log_pos() + inc_pos);//增加Read_Master_Log_Pos位点，为当前位置
      memcpy(rli->ign_master_log_name_end, mi->get_master_log_name(), FN_REFLEN); //进行拷贝
      DBUG_ASSERT(rli->ign_master_log_name_end[0]); //断言存在
      rli->ign_master_log_pos_end= mi->get_master_log_pos(); //忽略到位点
    }
主库：SQL线程会通过rli->ign_master_log_name_end[0]判定是否有需要跳过的Event，如果有则构建一个Rotate_log_event来跳过这个Event，代码如下：
if (rli->ign_master_log_name_end[0]) //如果跳过的Event存在
        {
          /* We generate and return a Rotate, to make our positions advance */
          DBUG_PRINT("info",("seeing an ignored end segment"));
          ev= new Rotate_log_event(rli->ign_master_log_name_end,
                                   0, rli->ign_master_log_pos_end, exec_relay_log_event
                                   Rotate_log_event::DUP_NAME); //构建一个Rotate Event，位置为
          rli->ign_master_log_name_end[0]= 0;                   //rli->ign_master_log_pos_end，执行这个Event就可以
          mysql_mutex_unlock(log_lock);exec_relay_log_event     //来更新Exec_Master_Log_Pos位点
          if (unlikely(!ev))
          {
            errmsg= "Slave SQL thread failed to create a Rotate event "
              "(out of memory?), SHOW SLAVE STATUS may be inaccurate";
            goto err;
          }
          ev->server_id= 0; // don't be ignored by slave SQL thread
          DBUG_RETURN(ev);
        }
好了到这里我们知道了Event在主库是如何跳过的，但是注意IO线程和SQL线程在处理Read_Master_Log_Pos和Exec_Master_Log_Pos的时候可能有一定的时间差，那么Read_Master_Log_Pos和Exec_Master_Log_Pos存在一定的差值的条件就可能会满足，则进入延迟计算环节。

最后需要注意的是实际上这种情况的延迟并没有问题，完全是一种偶尔出现的计算上的问题，是一种假象，如果主库的压力越大出现这种情况的可能性就会越大，因为IO线程和SQL线程在处理Read_Master_Log_Pos和Exec_Master_Log_Pos的出现时间差的可能性就会越大。
四、MTS下的延迟debug
其实知道了原理就很容易debug了，因为我们可以将断点放到主库的show_slave_status_send_data函数上，那么就能看出来了，做的操作如下：

从库flush binary logs
主库执行一些insert操作
主库show slave status
这个时候我们可以跳过（Read_Master_Log_Pos和Exec_Master_Log_Pos存在一定的差值）这个条件，直接通过公式去计算，得到如下结果：

(gdb) p (long)(time(0)- mi->rli->last_master_timestamp)- mi->clock_diff_with_master
$6 = 37
延迟就是37秒，因此我们的理论得到了验证。

下面一个debug结果是单SQL线程的，可以看到延迟更是大得离谱。

(gdb) p (long)(time(0)- mi->rli->last_master_timestamp)- mi->clock_diff_with_master
$7 = 1592672402

（编辑：ASP站长网）