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

Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server.

    XMLWordPrintable

    Details

      Description

      Aborting OPTIMIZE TABLE still logs in binary logs and replicates to the Slave server.

      It is observed that while OPTIMIZE TABLE query is executing, aborting it will still have the entry of the same in the binary logs and it's getting replicated at the slave end. Tested and found this behavior at MariaDB server 10.3.16 and 10.4.12.

      It doesn't look like an expected behavior and so reporting it.

      Here is my test result.

      Master:
      =======

      MariaDB [test]> show master status; ## Note the binary log position
      +---------------+----------+--------------+------------------+
      | File | Position | Binlog_Do_DB | Binlog_Ignore_DB |
      +---------------+----------+--------------+------------------+
      | binlog.000002 | 471 | | |
      +---------------+----------+--------------+------------------+
      1 row in set (0.000 sec)
       
      MariaDB [test]> optimize table foo; ## OPTIMIZE query was aborted
      ^CCtrl-C -- query killed. Continuing normally.
      +----------+----------+----------+-------------------------------------------------------------------+
      | Table | Op | Msg_type | Msg_text |
      +----------+----------+----------+-------------------------------------------------------------------+
      +----------+----------+----------+-------------------------------------------------------------------+
      3 rows in set, 1 warning (1.976 sec)
       
      MariaDB [test]> show master status; ## Binary log position changed
      +---------------+----------+--------------+------------------+
      | File | Position | Binlog_Do_DB | Binlog_Ignore_DB |
      +---------------+----------+--------------+------------------+
      | binlog.000002 | 598 | | |
      +---------------+----------+--------------+------------------+
      1 row in set (0.000 sec)
       
      MariaDB [test]> show binlog events in 'binlog.000002'; ## Binary log events, clearly showing OPTIMIZE query.
      +---------------+-----+-------------------+-----------+-------------+------------------------------------------------+
      | Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
      +---------------+-----+-------------------+-----------+-------------+------------------------------------------------+
      | binlog.000002 | 4 | Format_desc | 2 | 256 | Server ver: 10.4.12-MariaDB-log, Binlog ver: 4 |
      | binlog.000002 | 256 | Gtid_list | 2 | 299 | [0-1-44031] |
      | binlog.000002 | 299 | Binlog_checkpoint | 2 | 339 | binlog.000002 |
      | binlog.000002 | 339 | Gtid | 2 | 381 | GTID 0-2-44032 |
      | binlog.000002 | 381 | Query | 2 | 471 | use `test`; create table pp (a int) |
      | binlog.000002 | 471 | Gtid | 2 | 513 | GTID 0-2-44033 |
      | binlog.000002 | 513 | Query | 2 | 598 | use `test`; optimize table foo |
      +---------------+-----+-------------------+-----------+-------------+------------------------------------------------+
      7 rows in set (0.000 sec)
       
      MariaDB [test]> select @@version;
      +---------------------+
      | @@version |
      +---------------------+
      | 10.4.12-MariaDB-log |
      +---------------------+
      1 row in set (0.000 sec)
      

      Slave:
      ======

      You can see in the processlist, OPTIMIZE TABLE query is being executed. "show slave status" showed it moved to the changed master binary log position.

      MariaDB [(none)]> show processlist;
      +----+-------------+---------------------------------+------+-------------+------+-----------------------------------------------------------------------+--------------------+----------+
      | Id | User | Host | db | Command | Time | State | Info | Progress |
      +----+-------------+---------------------------------+------+-------------+------+-----------------------------------------------------------------------+--------------------+----------+
      | 4 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
      | 1 | system user | | NULL | Daemon | NULL | InnoDB purge coordinator | NULL | 0.000 |
      | 2 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
      | 3 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
      | 5 | system user | | NULL | Daemon | NULL | InnoDB shutdown handler | NULL | 0.000 |
      | 12 | root | localhost | NULL | Query | 0 | Init | show processlist | 0.000 |
      | 17 | root | test001.colo.sproutsys.com:51990 | NULL | Binlog Dump | 353 | Master has sent all binlog to slave; waiting for binlog to be updated | NULL | 0.000 |
      | 19 | system user | | NULL | Slave_IO | 82 | Waiting for master to send event | NULL | 0.000 |
      | 20 | system user | | test | Slave_SQL | 26 | Altering table | optimize table foo | 0.000 |
      +----+-------------+---------------------------------+------+-------------+------+-----------------------------------------------------------------------+--------------------+----------+
      9 rows in set (0.001 sec)
       
      MariaDB [(none)]> show slave status\G
      *************************** 1. row ***************************
      Slave_IO_State: Waiting for master to send event
      Master_Host: test001
      Master_User: root
      Master_Port: 3306
      Connect_Retry: 60
      Master_Log_File: binlog.000002
      Read_Master_Log_Pos: 598
      Relay_Log_File: zen010-relay-bin.000002
      Relay_Log_Pos: 684
      Relay_Master_Log_File: binlog.000002
      Slave_IO_Running: Yes
      Slave_SQL_Running: Yes
      Replicate_Do_DB:
      Replicate_Ignore_DB:
      Replicate_Do_Table:
      Replicate_Ignore_Table:
      Replicate_Wild_Do_Table:
      Replicate_Wild_Ignore_Table:
      Last_Errno: 0
      Last_Error:
      Skip_Counter: 0
      Exec_Master_Log_Pos: 471
      Relay_Log_Space: 1121
      Until_Condition: None
      Until_Log_File:
      Until_Log_Pos: 0
      Master_SSL_Allowed: No
      Master_SSL_CA_File:
      Master_SSL_CA_Path:
      Master_SSL_Cert:
      Master_SSL_Cipher:
      Master_SSL_Key:
      Seconds_Behind_Master: 9
      Master_SSL_Verify_Server_Cert: No
      Last_IO_Errno: 0
      Last_IO_Error:
      Last_SQL_Errno: 0
      Last_SQL_Error:
      Replicate_Ignore_Server_Ids:
      Master_Server_Id: 2
      Master_SSL_Crl:
      Master_SSL_Crlpath:
      Using_Gtid: No
      Gtid_IO_Pos:
      Replicate_Do_Domain_Ids:
      Replicate_Ignore_Domain_Ids:
      Parallel_Mode: conservative
      SQL_Delay: 0
      SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Altering table
      Slave_DDL_Groups: 1
      Slave_Non_Transactional_Groups: 1
      Slave_Transactional_Groups: 0
      1 row in set (0.000 sec)
      

      Any further details needed, let me know.

      Thank You,
      Suresh

        Attachments

          Activity

            People

            Assignee:
            sujatha.sivakumar Sujatha Sivakumar
            Reporter:
            suresh.ramagiri@mariadb.com suresh ramagiri
            Votes:
            0 Vote for this issue
            Watchers:
            9 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: