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.

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

        Issue Links

          Activity

            Elkin Andrei Elkin added a comment - - edited

            sujatha.sivakumar I think it's okay to binlog a killed Query regardless of the # of tables in it and also regardless of the KILL type. We would just state that in the docs. Go to ask serg about this possibility which looks quite harmless to me.

            As to no actual SOFT kill, we should open a new ticket for that (it does not look good to reuse the current one imo).

            Elkin Andrei Elkin added a comment - - edited sujatha.sivakumar I think it's okay to binlog a killed Query regardless of the # of tables in it and also regardless of the KILL type. We would just state that in the docs. Go to ask serg about this possibility which looks quite harmless to me. As to no actual SOFT kill, we should open a new ticket for that (it does not look good to reuse the current one imo).

            Hello Andrei,

            Please review the fix for MDEV-22530.
            MDEV-22530 fix is implemented on top of MDEV-17515 fix.

            https://github.com/MariaDB/server/commit/44eb746c226d3eabe93d476790bb0c6bb30106b2

            Please review top two commits:

            1. commit 44eb746c226d3eabe93d476790bb0c6bb30106b2
            MDEV-22530: Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server.

            2. commit 502a6b9b3ce119f507cb8ccc9ec034a9953ad3cc
            MDEV-17515: GTID Replication in optimistic mode deadlock

            Thank you.

            sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - Hello Andrei, Please review the fix for MDEV-22530 . MDEV-22530 fix is implemented on top of MDEV-17515 fix. https://github.com/MariaDB/server/commit/44eb746c226d3eabe93d476790bb0c6bb30106b2 Please review top two commits: 1. commit 44eb746c226d3eabe93d476790bb0c6bb30106b2 MDEV-22530 : Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server. 2. commit 502a6b9b3ce119f507cb8ccc9ec034a9953ad3cc MDEV-17515 : GTID Replication in optimistic mode deadlock Thank you.

            OK to push

            sachin.setiya.007 Sachin Setiya (Inactive) added a comment - OK to push

            MDEV-22530 and MDEV-17515 are related. MDEV-22530's fix is implemented on MDEV-17515's fix.

            Hence both are tested and pushed together.

            10.3: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.3-sujatha
            ====
            commit 07da206ccd21080351363a2c1f080320367c52bb (HEAD -> 10.3, origin/bb-10.3-sujatha)
            MDEV-22530: Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server.

            10.3 cherry-pick testing.

            commit e683e8c010bd2ffa9415857828e89f94b9ac0550
            MDEV-17515: GTID Replication in optimistic mode deadlock

            10.3 cherry-pick testing.

            10.4: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.4-sujatha
            ====
            commit 0f34165ec1427eccbf18db9f71744537fe6a1354 (HEAD -> 10.4, origin/bb-10.4-sujatha)
            MDEV-22530: Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server.

            10.4 cherry-pick testing.

            commit 4169e6571c342b57a3ce89e7ae45328c06beb788
            MDEV-17515: GTID Replication in optimistic mode deadlock

            10.4 cherry-pick testing.

            Merge conflicts addressed.
            Result file re-recorded.

            10.5: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.5-sujatha
            ====
            commit 0f9598100aa37f48e8eb93669396e9fac37c493a (HEAD -> 10.5, origin/bb-10.5-sujatha)
            MDEV-22530: Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server.

            10.5 cherry-pick testing.

            No Merge conflicts

            commit f0c220898fbe8f58393d386aa0cb6da6b7cedf9f
            MDEV-17515: GTID Replication in optimistic mode deadlock

            10.5 cherry-pick testing.

            Moved changes to log_event_server.cc

            sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - MDEV-22530 and MDEV-17515 are related. MDEV-22530 's fix is implemented on MDEV-17515 's fix. Hence both are tested and pushed together. 10.3: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.3-sujatha ==== commit 07da206ccd21080351363a2c1f080320367c52bb (HEAD -> 10.3, origin/bb-10.3-sujatha) MDEV-22530 : Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server. 10.3 cherry-pick testing. commit e683e8c010bd2ffa9415857828e89f94b9ac0550 MDEV-17515 : GTID Replication in optimistic mode deadlock 10.3 cherry-pick testing. 10.4: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.4-sujatha ==== commit 0f34165ec1427eccbf18db9f71744537fe6a1354 (HEAD -> 10.4, origin/bb-10.4-sujatha) MDEV-22530 : Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server. 10.4 cherry-pick testing. commit 4169e6571c342b57a3ce89e7ae45328c06beb788 MDEV-17515 : GTID Replication in optimistic mode deadlock 10.4 cherry-pick testing. Merge conflicts addressed. Result file re-recorded. 10.5: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.5-sujatha ==== commit 0f9598100aa37f48e8eb93669396e9fac37c493a (HEAD -> 10.5, origin/bb-10.5-sujatha) MDEV-22530 : Aborting OPTIMIZE TABLE still logs in binary log and replicates to the Slave server. 10.5 cherry-pick testing. No Merge conflicts commit f0c220898fbe8f58393d386aa0cb6da6b7cedf9f MDEV-17515 : GTID Replication in optimistic mode deadlock 10.5 cherry-pick testing. Moved changes to log_event_server.cc

            People

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

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.