InnoDB: xtrabackup: Last MySQL binlog file position info printed twice while backup prepare

[Shahriyar Rzayev]

Running following command:

/home/shahriyar.rzaev/XB_TEST/server_dir/target/percona-xtrabackup-2.4.x-debug/bin/xtrabackup --prepare --apply-log-only --target-dir=/home/shahriyar.rzaev/XB_TEST/backup_dir/ps_5_7_x_2_4/cycle1/full/2017-12-08_13-55-05 --slave-info --no-version-check --core-file --parallel=10 --throttle=40 --check-privileges --ftwrl-wait-timeout=0 --ftwrl-wait-query-type=all --ftwrl-wait-threshold=1 --kill-long-queries-timeout=1 --kill-wait-query-type=all --kill-long-query-type=all --no-backup-locks --keyring-file-data=/home/shahriyar.rzaev/XB_TEST/server_dir/PS061217-percona-server-5.7.20-18-linux-x86_64-debug/mysql-keyring/keyring

InnoDB: Progress in percent: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: xtrabackup: Last MySQL binlog file position 7770684, file name mysql-bin.000003
InnoDB: xtrabackup: Last MySQL binlog file position 7770684, file name mysql-bin.000003

xtrabackup: starting shutdown with innodb_fast_shutdown = 1
InnoDB: Starting shutdown...
InnoDB: Shutdown completed; log sequence number 36252648
InnoDB: Number of pools: 1
171208 13:58:14 completed OK!

As you noticed:
"InnoDB: xtrabackup: Last MySQL binlog file position 7770684, file name mysql-bin.000003" is printed twice.

trx_sys_print_mysql_binlog_offset() called in to print:

https://github.com/percona/percona-xtrabackup/blob/2.4/storage/innobase/xtrabackup/src/xtrabackup.cc#L7793

But it is also called in:

if (recv_needed_recovery) {
   trx_sys_print_mysql_binlog_offset();
}

https://github.com/percona/percona-xtrabackup/blob/2.4/storage/innobase/srv/srv0start.cc#L2221

According to:

/** TRUE when recv_init_crash_recovery() has been called. */
extern bool recv_needed_recovery;

The crash recovery is done and recv_needed_recovery is TRUE.
So maybe we can add a check if recv_needed_recovery is FALSE in xtrabackup.cc prior calling trx_sys_print_mysql_binlog_offset()

[Shahriyar Rzayev (rzayev-sehriyar)]

The 2.3 version is not affected because there is no call of trx_sys_print_mysql_binlog_offset() in srv0start.cc

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXB-955