MySQL Bugs: #99178: SBM returns a large value offenly because last_master

Bug #99178	SBM returns a large value offenly because last_master_timestamp is not updated
Submitted:	4 Apr 2020 13:04	Modified:	22 Nov 2021 7:13
Reporter:	Ling Yuan	Email Updates:
Status:	No Feedback	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S4 (Feature request)
Version:	5.7.22	OS:	Linux
Assigned to:	Assigned Account	CPU Architecture:	Any
Tags:	MTS, SBM, Seconds_Behind_Master

Description:
Our database service has a master and a slave, usually all the writings are on the master. We execute "show slave status;" on the master for monitoring, Normally Seconds_Behind_Master should return 0 or a small value, but we often receive a large value returned. 
The following are our related parameter settings：
log_slave_updates=on
slave_parallel_type=LOGICAL_CLOCK
slave_parallel_workers=8

We found that this problem exists on 5.7.22 ~ 5.7.26. I have readed the relevant source code, That should be a bug introduced since 5.7.22, and still not be solved in the latest GA version 5.7.29. We also used version 5.7.20, this will not have the same problem.

How to repeat:
1. flush logs on slave;
2. stop slave sql_thread on master;
3. DML on master. Observe "show slave status" at this time and you can see that Read_Master_Log_Pos is ahead.
4. Start slave on master; "show slave status" You can see Seconds_Behind_Master becomes larger

Suggested fix:
In the rpl_slave.cc: next_event function  , after calling the mts_checkpoint_routine function (in do..while), the following two lines of code are missing(I found that exists in 5.7.21):
if (rli->gaq->empty())
  rli->last_master_timestamp= 0;

sorry for my poor English

The following are logs captured online：

2020-03-19 21:26:47:
              Master_Log_File: antiaddiction-dp01-bin.000498
          Read_Master_Log_Pos: 401361668
               Relay_Log_File: antiaddiction-da01-relay-bin.000772
                Relay_Log_Pos: 393
        Relay_Master_Log_File: antiaddiction-dp01-bin.000498
          Exec_Master_Log_Pos: 401361637
        Seconds_Behind_Master: 7774
2020-03-19 21:28:10:
              Master_Log_File: antiaddiction-dp01-bin.000498
          Read_Master_Log_Pos: 405512424
               Relay_Log_File: antiaddiction-da01-relay-bin.000772
                Relay_Log_Pos: 393
        Relay_Master_Log_File: antiaddiction-dp01-bin.000498
          Exec_Master_Log_Pos: 405511551
        Seconds_Behind_Master: 7857
2020-03-19 21:28:35:
              Master_Log_File: antiaddiction-dp01-bin.000498
          Read_Master_Log_Pos: 406675839
               Relay_Log_File: antiaddiction-da01-relay-bin.000772
                Relay_Log_Pos: 393
        Relay_Master_Log_File: antiaddiction-dp01-bin.000498
          Exec_Master_Log_Pos: 406675808
        Seconds_Behind_Master: 7882

Hi,

Do you still observe the same issue with latest 5.7/8.0 ?

thanks

No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".