Shulou(Shulou.com)06/01 Report--

Original: https://www.enmotech.com/web/detail/1/789/1.html

Introduction: this article describes in detail the whole process of analysis and solution after the author manually registers the binlog file with the MySQL database to cause the master-slave synchronization exception.

I. the source of the problem

Because of some requirements, he wants to restore the backed-up binlog files to the master library and register them. Without turning off master-slave synchronization, he does the following:

1. Some backed up binlog files are added to the binlog log directory files.

two。 Modify the index files to add these binlog files.

3. Flush binary logs registration file.

After doing this, the master library did register back in binlog, but there was a lot of delay throughout the master-slave environment.

Second, the first test

The test operations are as follows:

1. Master library operation, copy and clean up binlog

(root:db1@xucl:10:30:22) [(none)] > show binary logs

+-+ +

| | Log_name | File_size |

+-+ +

| | mysql-binlog.000035 | 2134 | |

| | mysql-binlog.000036 | 845915 | |

| | mysql-binlog.000037 | 11735 | |

| | mysql-binlog.000038 | 284 |

| | mysql-binlog.000039 | 284 |

| | mysql-binlog.000040 | 284 |

| | mysql-binlog.000041 | 284 |

| | mysql-binlog.000042 | 234 | |

+-+ +

12 rows in set (0.00 sec)

Copy the binlog that needs to be cleaned to the backup directory, that is, binlog 35, 36, 37, 38.

(root:db1@xucl:10:30:34) [(none)] > purge binary logs to 'mysql-binlog.000039'

Query OK, 0 rows affected (0.00 sec)

(root:db1@xucl:10:30:49) [(none)] > show binary logs

+-+ +

| | Log_name | File_size |

+-+ +

| | mysql-binlog.000039 | 284 |

| | mysql-binlog.000040 | 284 |

| | mysql-binlog.000041 | 284 |

| | mysql-binlog.000042 | 234 | |

+-+ +

4 rows in set (0.00 sec)

two。 Master library operation, copy the backed-up binlog back to the original directory and modify the index file for registration

[root@izbp12nspj47ypto9t6vyez logs] # ll

-rw-r- 1 mysql mysql 2134 May 20 22:03 mysql-binlog.000035

-rw-r- 1 mysql mysql 845915 May 20 22:03 mysql-binlog.000036

-rw-r- 1 mysql mysql 11735 May 20 22:05 mysql-binlog.000037

-rw-r- 1 mysql mysql 284 May 20 22:06 mysql-binlog.000038

-rw-r- 1 mysql mysql 284 May 21 10:28 mysql-binlog.000039

-rw-r- 1 mysql mysql 284 May 21 10:28 mysql-binlog.000040

-rw-r- 1 mysql mysql 284 May 21 10:28 mysql-binlog.000041

-rw-r- 1 mysql mysql 491 May 21 10:31 mysql-binlog.000042

-rw-r- 1 mysql mysql 204 May 21 10:30 mysql-binlog.index

3. Main library operation, main library flush binary logs

(root:db1@xucl:10:32:51) [(none)] > flush binary logs

Query OK, 0 rows affected (0.01 sec)

(root:db1@xucl:10:32:57) [(none)] > show binary logs

+-+ +

| | Log_name | File_size |

+-+ +

| | mysql-binlog.000035 | 2134 | |

| | mysql-binlog.000036 | 845915 | |

| | mysql-binlog.000037 | 11735 | |

| | mysql-binlog.000038 | 284 |

| | mysql-binlog.000039 | 284 |

| | mysql-binlog.000040 | 284 |

| | mysql-binlog.000041 | 284 |

| | mysql-binlog.000042 | 541 |

| | mysql-binlog.000043 | 234 | |

+-+ +

13 rows in set (0.00 sec)

4. At this point, from the library operation, show slave status

The error is as follows:

Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'Cannot replicate GTID-

Transaction when @ @ GLOBAL.GTID_MODE = OFF, at file / storage/single/mysql3306/logs/mysql-binlog.000035, position 194.

5. Error observation

From the point of view of this error, after the main library flush binary logs, depending on the DUMP thread of the main library re-sending the old mysql-binlog.000035 binlog. The error is reported because it used to be GTID mode, but it has been changed to POSITION mode during testing, which is reported by the master library DUMP thread when checking whether the GTID Event mode of the master library and the GTID mode of the slave library are compatible, as shown in the following figure

This error is not important here, we just need to know that the old binlog mysql-binlog.000035 has been sent again.

Third, the operation of flush binary logs to binlog

Flush binary logs consists of at least the following operations:

Get the new binlog file name

Turn off the old binlog

Close index file

Open index file

Open a new binlog

Add a new binlog to indexfile

Judge whether binlog deletion is needed according to the parameter expire_logs_days

For more information, please see the function MYSQL_BIN_LOG::new_file_impl. Note that getting the new binlog file name is achieved through the function find_uniq_filename, which contains the following code:

File_info= dir_info- > dir_entry

For (I = dir_info- > number_off_files; iMub -; file_info++)

{

If (strncmp (file_info- > name, start, length) = = 0 &

Is_number (file_info- > name+length, & number,0))

{

Set_if_bigger (max_found, number)

}

}

...

* next= (need_next | | max_found = = 0)? Max_found + 1: max_found

Scan the binlog file in the binlog directory to get the one with the highest serial number, and then add 1. So even if we modify index file,flush binary logs manually, it won't be a problem, because it actually scans the binlog file. At the same time, we also see that flush binary logs reloads index file, when the manually modified index file takes effect, and you can view the files you manually added using show binary logs.

The stack frames are as follows:

# 0 find_uniq_filename (name=0x7fffec5ec6d0 "/ mysqldata/mysql3340/log/binlog", next=0x7fffec5ec678, need_next=true)

At / mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:3679

# 1 0x000000000187d208 in generate_new_log_name (new_name=0x7fffec5ec6d0 "/ mysqldata/mysql3340/log/binlog", new_ext=0x0

Log_name=0x7ffedc011520 "/ mysqldata/mysql3340/log/binlog", is_binlog=true) at / mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:3767

# 2 0x0000000001884fdb in MYSQL_BIN_LOG::new_file_impl (this=0x2e83640, need_lock_log=false, extra_description_event=0x0)

At / mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:7175

# 3 0x0000000001884cbb in MYSQL_BIN_LOG::new_file_without_locking (this=0x2e83640, extra_description_event=0x0)

At / mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:7099

# 4 0x0000000001886b6b in MYSQL_BIN_LOG::rotate (this=0x2e83640, force_rotate=true, check_purge=0x7fffec5ecbfb)

At / mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:7775

# 5 0x0000000001886d53 in MYSQL_BIN_LOG::rotate_and_purge (this=0x2e83640, thd=0x7ffedc000b90, force_rotate=true)

At / mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:7846

IV. The emergence of the problem of master and slave

After the binlog switch, the DUMP thread also needs to read the next binlog file, but the process of getting it is completely different from that of flush binary logs. The code that loops through each binlog file can be found in the function Binlog_sender::run. The following sentence is to find the next binlog file:

Int error= mysql_bin_log.find_next_log (& m_linfo, 0)

The code contained in mysql_bin_log.find_next_log is:

My_b_seek (& index_file, linfo- > index_file_offset); / / offset

Linfo- > index_file_start_offset= linfo- > index_file_offset

Length=my_b_gets (& index_file, fname, FN_REFLEN); / / read the file name

...

If (normalize_binlog_name (full_fname, fname, is_relay_log))

...

Linfo- > index_file_offset= my_b_tell (& index_file); / / offset from the new record for next use

We can see that the DUMP thread does not actually scan the entire index file, but reads it through the offset of an index file. If the index file is manually modified, the offset will not be maintained, and the next file sent by DUMP will be uncertain, so the manually registered binlog file will be sent to the slave library. Depending on the master and slave settings, the following will occur:

If GTID_MODE is turned off and POSITION is used, then this situation must report an error, such as duplicate lines, which we will test below.

If it is GTID_MODE and AUTO_POSITION=1, then the DUMP thread filters the GTID and does not send, because the Event does not send, so the delay will last for a period of 0.

If it is GTID_MODE and AUTO_POSITION=0, then the DUMP thread will actually send these Event, but the SQL thread will filter according to the GTID when it is applied, and the delay may be very large.

In addition, we need to consider why purge binary logs will delete binlog, because purge binary logs will actually maintain this offset by calling Adjust_offset::operator () in the function adjust_linfo_offsets. The code is as follows:

Linfo- > index_file_offset-= m_purge_offset

5. Practical testing

Let's test for GTID_MODE shutdown, using POSITION, and primary key conflicts.

1. Test tables and related environments

Mysql > show binary logs

+-+ +

| | Log_name | File_size |

+-+ +

| | binlog.000001 | 198 | |

| | binlog.000002 | 154 | |

+-+ +

2 rows in set (0.00 sec)

Mysql > show create table testcp\ G

* * 1. Row *

Table: testcp

Create Table: CREATE TABLE `testcp` (

`id`int (11) NOT NULL

PRIMARY KEY (`id`)

) ENGINE=InnoDB DEFAULT CHARSET=utf8

1 row in set (0.00 sec)

ERROR:

No query specified

two。 Execute a statement

Main library:

Mysql > insert into testcp values (20)

Query OK, 1 row affected (0.43 sec)

Mysql > select * from testcp

+-- +

| | id |

+-- +

| | 10 |

| | 20 |

+-- +

2 rows in set (0.01sec)

From the library:

Mysql > show slave status\ G

* * 1. Row *

...

Master_Log_File: binlog.000002

Read_Master_Log_Pos: 417

Relay_Log_File: relay.000004

Relay_Log_Pos: 624

Relay_Master_Log_File: binlog.000002

Slave_IO_Running: Yes

Slave_SQL_Running: Yes

...

Mysql > select * from testcp

+-- +

| | id |

+-- +

| | 10 |

| | 20 |

+-- +

At this time, the DUMP thread index file offset pointer is as follows, as shown below:

3. The main library executes purge binary logs

Copy the original binlog.000001 to binlog.000001bak before doing it, because you have to copy it back later.

Mysql > purge binary logs to 'binlog.000002'

Query OK, 0 rows affected (3.14 sec)

Mysql > show binary logs

+-+ +

| | Log_name | File_size |

+-+ +

| | binlog.000002 | 417 |

+-+ +

1 row in set (0.00 sec)

Because the purge binary logs command maintains the offset pointer, the index file offset pointer for the DUMP thread is as follows, as shown below:

4. Copy the backup binlog back and modify the index file

Copy binlog.000001bak to binlog.000001, modify index file to add binlog.000001 back, and then flush binary logs as follows:

Mysql > flush binary logs

Query OK, 0 rows affected (0.15 sec)

Mysql > show binary logs

+-+ +

| | Log_name | File_size |

+-+ +

| | binlog.000001 | 198 | |

| | binlog.000002 | 461 |

+-+ +

2 rows in set (0.00 sec)

Doing this manually does not maintain the index file offset pointer of the DUMP thread, as shown in the following figure:

By this time we have seen that the offset pointer is out of order, and then the DUMP thread will send the binlog.000002 again.

5. Error observation

In this way, the DUMP thread re-sends the content of binlog.000002. The slave library of POSITION mode can only report an error as follows. We can see that a duplicate line occurs, and error 1062 is as follows:

LAST_ERROR_MESSAGE: Worker 1 failed executing transaction 'ANONYMOUS' at master log binlog.000002

End_log_pos 386; Could not execute Write_rows event on table testmts.testcp; Duplicate entry'20 'for key

'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log

Binlog.000002, end_log_pos 386

VI. Summary

We can see that this operation is very irregular, and if you really want to do this, consider the following steps:

Close all slave libraries

Manually register binlog files and modify index files

Flush binary logs

Start the slave library

Rebooting from the library in this way will reinitialize DUMP's index file offset pointer, which should be no problem. However, you should try to avoid such operations, because both index file and binlog are maintained by MySQL itself.

Original: Gao Peng (eight eccentrics), now Yi Jifu senior DBA, engaged in Oracle/MySQL related work for more than 10 years Oracle OCM has rich database performance tuning fault diagnosis experience, some research on MySQL source code. Author of "in-depth understanding of the principle of MySQL Master and Slave". Please follow "going deep into MySQL master-slave principle section 32", address: http://j.youzan.com/yEY_Xi.

Want to know more about databases and cloud technologies?

Come and follow the official account of "data and Cloud" and the official website of "Yunhe Enmo". We look forward to learning and making progress with you!

(scan the QR code above and follow the official account of "data and Cloud" for more science and technology articles.)

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.