Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-22351

InnoDB may report incorrect binlog position information after RESET MASTER

    XMLWordPrintable

    Details

      Description

      RESET MASTER should be propagated to InnoDB to actually clear all information from the rseg header pages.

      Observation:

      Start a server with binary log option being enabled.
      Create a simple table and insert couple of rows.

      MariaDB [test]> show binlog events;
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      | Log_name          | Pos | Event_type        | Server_id | End_log_pos | Info                                                 |
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      | master-bin.000001 |   4 | Format_desc       |         1 |         256 | Server ver: 10.3.23-MariaDB-debug-log, Binlog ver: 4 |
      | master-bin.000001 | 256 | Gtid_list         |         1 |         285 | []                                                   |
      | master-bin.000001 | 285 | Binlog_checkpoint |         1 |         329 | master-bin.000001                                    |
      | master-bin.000001 | 329 | Gtid              |         1 |         371 | GTID 0-1-1                                           |
      | master-bin.000001 | 371 | Query             |         1 |         481 | use `test`; create table t ( f int ) engine=innodb   |
      | master-bin.000001 | 481 | Gtid              |         1 |         523 | BEGIN GTID 0-1-2                                     |
      | master-bin.000001 | 523 | Query             |         1 |         620 | use `test`; insert into t values (10)                |
      | master-bin.000001 | 620 | Xid               |         1 |         651 | COMMIT /* xid=7 */                                   |
      | master-bin.000001 | 651 | Gtid              |         1 |         693 | BEGIN GTID 0-1-3                                     |
      | master-bin.000001 | 693 | Query             |         1 |         790 | use `test`; insert into t values (20)                |
      | master-bin.000001 | 790 | Xid               |         1 |         821 | COMMIT /* xid=8 */                                   |
      | master-bin.000001 | 821 | Stop              |         1 |         844 |                                                      |
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      

      Shutdown and restart server

      Debug prints: From mysqld.1.err

      ****** BEFORE *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:651
      ----recovered_binlog_name:
      ----recovered_binlog_offset:0
      ****** AFTER *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:651
      ----recovered_binlog_name:./master-bin.000001
      ----recovered_binlog_offset:651
      ****** BEFORE *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:821
      ----recovered_binlog_name:./master-bin.000001
      ----recovered_binlog_offset:651
      ****** AFTER *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:821
      ----recovered_binlog_name:./master-bin.000001
      ----recovered_binlog_offset:821
      

      Execute RESET MASTER on restarted server. // This will clear existing binary logs and a fresh 'master-bin.000001' is created.

      MariaDB [test]> RESET MASTER;
      Query OK, 0 rows affected (0.002 sec)
       
      MariaDB [test]> create table t2( f int) engine=innodb;
      Query OK, 0 rows affected (0.006 sec)
       
      MariaDB [test]> insert into t2 values (30);
      Query OK, 1 row affected (0.003 sec)
       
      MariaDB [test]> show binlog events;
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      | Log_name          | Pos | Event_type        | Server_id | End_log_pos | Info                                                 |
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      | master-bin.000001 |   4 | Format_desc       |         1 |         256 | Server ver: 10.3.23-MariaDB-debug-log, Binlog ver: 4 |
      | master-bin.000001 | 256 | Gtid_list         |         1 |         285 | []                                                   |
      | master-bin.000001 | 285 | Binlog_checkpoint |         1 |         329 | master-bin.000001                                    |
      | master-bin.000001 | 329 | Gtid              |         1 |         371 | GTID 0-1-1                                           |
      | master-bin.000001 | 371 | Query             |         1 |         480 | use `test`; create table t2( f int) engine=innodb    |
      | master-bin.000001 | 480 | Gtid              |         1 |         522 | BEGIN GTID 0-1-2                                     |
      | master-bin.000001 | 522 | Query             |         1 |         620 | use `test`; insert into t2 values (30)               |
      | master-bin.000001 | 620 | Xid               |         1 |         651 | COMMIT /* xid=9 */                                   |
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      

      Shutdown and restart. Observe the following output.
      'recovered_binlog_name' and 'position' are still referring to old 'master-bin.000001' and '821'.

      ****** BEFORE *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:651
      ----recovered_binlog_name:
      ----recovered_binlog_offset:0
      ****** AFTER *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:651
      ----recovered_binlog_name:./master-bin.000001
      ----recovered_binlog_offset:651
      ****** BEFORE *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:821
      ----recovered_binlog_name:./master-bin.000001
      ----recovered_binlog_offset:651
      ****** AFTER *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:821
      ----recovered_binlog_name:./master-bin.000001
      ----recovered_binlog_offset:821
      

      Shutdown and restart server.

      A new binary log is created.
      Now do a DML. With this latest binlog file name and pos are 'master-bin.000002' and pos=514

      MariaDB [test]> show binlog events in 'master-bin.000002';
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      | Log_name          | Pos | Event_type        | Server_id | End_log_pos | Info                                                 |
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      | master-bin.000002 |   4 | Format_desc       |         1 |         256 | Server ver: 10.3.23-MariaDB-debug-log, Binlog ver: 4 |
      | master-bin.000002 | 256 | Gtid_list         |         1 |         299 | [0-1-2]                                              |
      | master-bin.000002 | 299 | Binlog_checkpoint |         1 |         343 | master-bin.000002                                    |
      | master-bin.000002 | 343 | Gtid              |         1 |         385 | BEGIN GTID 0-1-3                                     |
      | master-bin.000002 | 385 | Query             |         1 |         483 | use `test`; insert into t2 VALUES (40)               |
      | master-bin.000002 | 483 | Xid               |         1 |         514 | COMMIT /* xid=5 */                                   |
      +-------------------+-----+-------------------+-----------+-------------+------------------------------------------------------+
      

      shutdown and restart. Since 'TRX_RSEG' file and pos are > 'recovered_binlog_name/offset' the 'recovered_binlog_name/offset' get proper assignments.

      ****** BEFORE *********
      ----TRX_RSEG: binlog name:./master-bin.000002
      ----TRX_RSEG: binlog_offset:514
      ----recovered_binlog_name:
      ----recovered_binlog_offset:0
      ****** AFTER *********
      ----TRX_RSEG: binlog name:./master-bin.000002
      ----TRX_RSEG: binlog_offset:514
      ----recovered_binlog_name:./master-bin.000002
      ----recovered_binlog_offset:514
      ****** BEFORE *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:651
      ----recovered_binlog_name:./master-bin.000002
      ----recovered_binlog_offset:514
      ****** AFTER *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:651
      ----recovered_binlog_name:./master-bin.000002
      ----recovered_binlog_offset:514
      ****** BEFORE *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:821
      ----recovered_binlog_name:./master-bin.000002
      ----recovered_binlog_offset:514
      ****** AFTER *********
      ----TRX_RSEG: binlog name:./master-bin.000001
      ----TRX_RSEG: binlog_offset:821
      ----recovered_binlog_name:./master-bin.000002
      ----recovered_binlog_offset:514
      

      Following debug prints were used to observe the behavior:

      diff --git a/storage/innobase/trx/trx0rseg.cc b/storage/innobase/trx/trx0rseg.cc
      index 46fb2680371..842718ce81d 100644
      --- a/storage/innobase/trx/trx0rseg.cc
      +++ b/storage/innobase/trx/trx0rseg.cc
      @@ -453,6 +453,14 @@ trx_rseg_mem_restore(trx_rseg_t* rseg, trx_id_t& max_trx_id, mtr_t* mtr)
               if (rseg_header[TRX_RSEG_BINLOG_NAME]) {
                   const char* binlog_name = reinterpret_cast<const char*>
                       (rseg_header) + TRX_RSEG_BINLOG_NAME;
      +            fprintf(stderr,"****** BEFORE *********\n");
      +            fprintf(stderr,"----TRX_RSEG: binlog name:%s\n", binlog_name);
      +            fprintf(stderr,"----TRX_RSEG: binlog_offset:%lu\n",
      +                 mach_read_from_8(rseg_header + TRX_RSEG_BINLOG_OFFSET));
      +            fprintf(stderr,"----recovered_binlog_name:%s\n",
      +                trx_sys.recovered_binlog_filename);
      +            fprintf(stderr,"----recovered_binlog_offset:%lu\n",
      +                trx_sys.recovered_binlog_offset);
                   compile_time_assert(TRX_RSEG_BINLOG_NAME_LEN == sizeof
                               trx_sys.recovered_binlog_filename);
       
      @@ -478,6 +486,14 @@ trx_rseg_mem_restore(trx_rseg_t* rseg, trx_id_t& max_trx_id, mtr_t* mtr)
                               = binlog_offset;
                       }
                   }
      +            fprintf(stderr,"****** AFTER *********\n");
      +            fprintf(stderr,"----TRX_RSEG: binlog name:%s\n", binlog_name);
      +            fprintf(stderr,"----TRX_RSEG: binlog_offset:%lu\n",
      +                 mach_read_from_8(rseg_header + TRX_RSEG_BINLOG_OFFSET));
      +            fprintf(stderr,"----recovered_binlog_name:%s\n",
      +                trx_sys.recovered_binlog_filename);
      +            fprintf(stderr,"----recovered_binlog_offset:%lu\n",
      +                trx_sys.recovered_binlog_offset);
       

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              marko Marko Mäkelä
              Reporter:
              sujatha.sivakumar Sujatha Sivakumar
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Git Integration