Solution to the problem of MySQL data delay jump

Today we analyzed another typical problem about database delay jump. In this process, we also provided some methods and techniques for analyzing the problem for reference.

First, in the high availability test, there is a set of environment detection intermittent. After investigation, it is found that the database has a delay. When logging in to the slave library to check the show slave status, it is found that the value of Seconds_behind_master is constantly jumping, that is, it keeps jumping from 0~39~0~39 at a frequency, which makes people very angry.

After checking the relevant logs of the database, I found that there were no log records for reference. How to analyze this problem? Let's reproduce it first, so I captured the logs of the problem three times according to the rhythm, that is, continuous monitoring through show slave status, capturing the output results of show slave status and saving them. In this way, we can get the offset change during the occurrence of a problem, and this change is the problem caused by SQLThread during the playback process.

For example, in the following output, I intercepted the relay log of the slave side for analysis. The corresponding field is Relay_Log_Pos

Slave_IO_State: Waiting for master to send event
         Master_Host: xxxx
         Master_User: dba_repl
         Master_Port: 4306
        Connect_Retry: 60
       Master_Log_File:mysqlbin.000044
     Read_Master_Log_Pos: 386125369
        Relay_Log_File: slave-relay-bin.000066
        Relay_Log_Pos: 386125580
    Relay_Master_Log_File: mysqlbin.000044

So we quickly get the change in offset: 385983806, 386062813, 386125580

Then I used mysqlbinlog to start analyzing the details of these log processes. According to the following command, I can quickly get three related tables in the dumped logs.

# grep INSERT relaylog_xxxx.dump |awk '{print $3 " " $4}'|sed 's/INTO//g'|sort|uniq
 act_action_exec_info
 act_join_desc
 dic_subsidy_marketing_querylog_202008

I gradually analyzed the data operations of each table, but the information I obtained was still limited. I continued to do further analysis, for example, let's analyze the transaction volume in the entire log:

# mysqlbinlog slave-relay-bin.000066 | grep "GTID$(printf '\t')last_committed" -B 1 \
> | grep -E '^# at' | awk '{print $3}' \
> | awk 'NR==1 {tmp=$1} NR>1 {print ($1-tmp);tmp=$1}' \
> | sort -n -r | head -n 100
mysqlbinlog: [Warning] unknown variable 'loose-default-character-set=utf8'
5278
5268
5268
5268
5253
5253
5253
5253
5253

It can be seen that it is about 5K, which is relatively large. Where does this additional information come from? I have enabled general_log in the main database, so that I can get more fine-grained operation logs.

Further analysis revealed that the entire business used the explicit transaction method: SET autocommit=0. The entire transaction contained several large SQL statements, which stored a lot of operation log details. In addition, during the transaction operation, multiple select count(1) from xxx operations were called based on the Mybatis framework.

After communicating with the business, the above issues have been basically clarified.

The above is the detailed solution to the problem of MySQL data delay and jump. For more information about MySQL data delay and jump, please pay attention to other related articles on 123WORDPRESS.COM!