Bug #80456 Add column end_log_pos/Last-Exec_master_Log_Pos when SHOW BINARY LOGS
Submitted: 21 Feb 2016 3:11 Modified: 22 Feb 2016 1:21
Reporter: Emanuel Calvo (OCA) Email Updates:
Status: Open Impact on me:
None 
Category:MySQL Server Severity:S4 (Feature request)
Version: OS:Any
Assigned to: CPU Architecture:Any

[21 Feb 2016 3:11] Emanuel Calvo
Description:
Description:
When issuing SHOW BINARY LOGS, it will be very useful to have in a 2nd column, the value of the end_log_pos of the rotated file. This value will help to fix replication issues easily, as this positions is the one that matches with Exec_master_Log_Pos in the slave when master rotates after a restart.

When orphan transactions place into the master's binary log that were not catch up by an slave, the replication brakes when master comes online. That is, the gsets differs and some transactions needs to be purged to force the slave thread to request the set again.

When something like this happens, it gives the DBA the information that the last transaction in the master's binary log, has been applied (It adds consistency visibility).

How to repeat:

This is a feature request.

Suggested fix:

I did a flight overview of the sql/binlog.cc implementation and I thought that this could be one way to implement this without implacting performance and stability. 

Code is approximately, didn't test or implemented yet. Using head version.

Pass end_log_pos when rotation is called :

char * end_log_pos_str = (char*)(&end_log_pos);

add_log_to_index((uchar*) end_log_pos_str, strlen(end_log_pos_str),
                 (uchar*) log_file_name, strlen(log_file_name),
                 need_lock_index))

Inside add_log_to_index:

                 if (my_b_write(&crash_safe_index_file, log_name, log_name_len) ||
                     my_b_write(&crash_safe_index_file, (uchar*) "\n", 1) ||
                     flush_io_cache(&crash_safe_index_file) ||
                     mysql_file_sync(crash_safe_index_file.file, MYF(MY_WME)))
                 {
                   sql_print_error("MYSQL_BIN_LOG::add_log_to_index failed to "
                                   "append log file name: %s, to crash "
                                   "safe index file.", log_name);
                   goto err;
                 }

inline_mysql_file_sync function at include/mysql/psi/mysql_file.h should have a
third parameter with this value. And insert the end_log_pos in the previous line:

if (my_b_write(&crash_safe_index_file, end_log_pos_str, end_log_pos_str_len) ||
    my_b_write(&crash_safe_index_file, (uchar*) "\n", 1) ||
    my_b_write(&crash_safe_index_file, log_name, log_name_len) ||
    my_b_write(&crash_safe_index_file, (uchar*) "\n", 1) ||
    flush_io_cache(&crash_safe_index_file) ||
    mysql_file_sync(crash_safe_index_file.file, MYF(MY_WME)))
{
  sql_print_error("MYSQL_BIN_LOG::add_log_to_index failed to "
                  "append log file name: %s, to crash "
                  "safe index file.", log_name);
  goto err;
}

Desirable output:

$ cat mysql-bin.index
./mysql-bin.000001 618
./mysql-bin.000002 1209
./mysql-bin.000003 1209
./mysql-bin.000004 1325
./mysql-bin.000005 1169
./mysql-bin.000006 

We don't need to update at every commit_stage or other calls, just only when do_rotate
is true.

When SHOW BINARY LOGS, the additional column can contain this number as the 
Last Exec Master Position or end_log_pos column name.

Can be done asynchronously and badly as this (only for fixing purposes):

➜  data for i in $(< mysql-bin.index) ; do echo $i $(../../../../mysqlDownloads/5.7.9/bin/mysqlbinlog  --base64-output='NEVER'  $i 2>/dev/null | tac | grep -Po -m1 '(?<=(end_log_pos\s))[[:digit:]]*') ; done 
./mysql-bin.000001 618
./mysql-bin.000002 1209
./mysql-bin.000003 1209
./mysql-bin.000004 1325
./mysql-bin.000005 1169
./mysql-bin.000006 154
[22 Feb 2016 1:21] Emanuel Calvo
I have partial good news. Actually this value can be extracted in the relay_slave_log_info table/file:

slave1 [localhost] {msandbox} (mysql) > select * from slave_relay_log_info\G
*************************** 1. row ***************************
  Number_of_lines: 7
   Relay_log_name: ./mysql-relay.000005
    Relay_log_pos: 238
  Master_log_name: mysql-bin.000004
   Master_log_pos: 4                  ** Here is the value I want **
        Sql_delay: 0
Number_of_workers: 0
               Id: 1
1 row in set (0,00 sec)

The problem is that the correct information in  slave_relay_log_info is not warranted on this version:

http://bugs.mysql.com/bug.php?id=68525
http://bugs.mysql.com/bug.php?id=71695

Also, we must consider that the update of this information is also sync_relay_log_info. That is, if the database does not shutdown properly it loses the information when using relay_log_info_repository=FILE and using TABLE for the cases on 68525.