InnoDB also stores the data's corresponding binary log position in its global tablespace.
It seems as though mariabackup does not currently update the binary log position stored in InnoDB during the prepare. This has a tendency to confuse users, since they see mismatching binary log positions.
For example, they might see something like this in the prepare output written by mariabackup:
2020-01-31 1:58:55 0 \[Note\] InnoDB: Last binlog file '/binlogs/mysql\-bin.014960', position 54640630
\[00\] 2020-01-31 01:58:56 Last binlog file /binlogs/mysql\-bin.014960, position 54640630
\[00\] 2020-01-31 01:58:57 completed OK!
And they might see a mismatched binary log position in xtrabackup_binlog_info:
To prevent confusion, when mariabackup prepares a backup, it should probably parse the binary log position from xtrabackup_binlog_info, and then use that position to update the binary log position in InnoDB.
Attachments
Issue Links
relates to
MDEV-22351InnoDB may report incorrect binlog position information after RESET MASTER
Closed
MDEV-23080mariabackup: position saved in xtrabackup_binlog_info is incorrect for replication
Closed
MDEV-23586Mariabackup: GTID saved for replication in 10.4.14 is wrong
mariabackup must not update binlog position during prepare, as it fetches it under either FTWRL (10.[23]) or under BLOCK_COMMIT(10.4+), which must block any binary log updates. This is more likely the bug on server-side locking. We already found similar bug - MDEV-23586, it's affected version is 10.4.14. It might cause the problem described in this report. At the moment we don't know affected versions of this bug, we need to develop test case to determine it. So I set Fix Version to N/A and update it after test is developed.
Vladislav Lesin
added a comment - mariabackup must not update binlog position during prepare, as it fetches it under either FTWRL (10. [23] ) or under BLOCK_COMMIT(10.4+), which must block any binary log updates. This is more likely the bug on server-side locking. We already found similar bug - MDEV-23586 , it's affected version is 10.4.14. It might cause the problem described in this report. At the moment we don't know affected versions of this bug, we need to develop test case to determine it. So I set Fix Version to N/A and update it after test is developed.
[00] 2020-11-02 11:41:49 mariabackup: The latest check point (for incremental): '7475872826954'
mariabackup: Stopping log copying thread.[00] 2020-11-02 11:41:49 >> log scanned up to (7475872827036)
[00] 2020-11-02 11:41:49 >> log scanned up to (7475872827036)
[00] 2020-11-02 11:41:49 Executing BACKUP STAGE END
[00] 2020-11-02 11:41:49 All tables unlocked
[00] 2020-11-02 11:41:49 Streaming ib_buffer_pool to <STDOUT>
[00] 2020-11-02 11:41:49 ...done
[00] 2020-11-02 11:41:49 Backup created in directory '/var/lib/mysql/xtrabackup_backupfiles/'
[00] 2020-11-02 11:41:49 MySQL binlog position: filename 'mariadb-bin.014113', position '360999250', GTID of the last change '0-40-3424141692,1-1-3051765148'
mariabackup must not update binlog position during prepare, as it fetches it under either FTWRL (10.[23]) or under BLOCK_COMMIT(10.4+), which must block any binary log updates. This is more likely the bug on server-side locking. We already found similar bug -
MDEV-23586, it's affected version is 10.4.14. It might cause the problem described in this report. At the moment we don't know affected versions of this bug, we need to develop test case to determine it. So I set Fix Version to N/A and update it after test is developed.