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

binlog.binlog_stm_drop_tmp_tbl fails in buildbot with Unknown table on exec

Details

    Description

      http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos73-ppc64le/builds/9249

      bb-10.1-release 4177181e1617df185397ea275ee98eb4

      binlog.binlog_stm_drop_tmp_tbl 'innodb_plugin,mix' w3 [ fail ]
              Test ended at 2019-07-26 10:12:03
       
      CURRENT_TEST: binlog.binlog_stm_drop_tmp_tbl
      ERROR 1051 (42S02) at line 77: Unknown table 'test.t1'
      mysqltest: In included file "./extra/binlog_tests/drop_temp_table.test": 
      included from /usr/share/mysql-test/suite/binlog/t/binlog_stm_drop_tmp_tbl.test at line 6:
      At line 168: exec of '/usr/bin/mysql --defaults-file=/dev/shm/var/3/my.cnf < /dev/shm/var/3/tmp/bug28642318.sql' failed, error: 256, status: 1, errno: 95
      Output from before failure:
      # DROP table query fails with unknown table error without patch.
       
       
       
      The result from queries just before the failure was:
      < snip >
      RESET MASTER;
      # Set up.
      SET @save_binlog_format= @@session.binlog_format;
      SET @@session.binlog_format=STATEMENT;
      CREATE TABLE t1 (a INT) ENGINE=INNODB;
      SET @@session.binlog_format=STATEMENT;
      CREATE TEMPORARY TABLE t1 (b BLOB) ENGINE=INNODB;
      DELETE d1, d2 FROM t1 AS d1, t1 AS d2 WHERE d1.a<>d2.a;
      DROP TABLE t1;
      # DELETE query fails with table re-open error without patch.
      # Clean up.
      DROP TABLE IF EXISTS t1;
      DROP TABLE IF EXISTS t1;
      RESET MASTER;
      # Test case for DROP query.
      CREATE TABLE t1 (a INT) ENGINE=INNODB;
      CREATE TEMPORARY TABLE t1 (b BLOB) ENGINE=INNODB;
      DROP TABLE t1;
      DROP TABLE t1;
      # DROP table query fails with unknown table error without patch.
      

      Attachments

        Activity

          ```
          #190805 23:02:29 server id 1 end_log_pos 231 CRC32 0xf24eb6b3 Query thread_id=85 exec_time=0 error_code=0
          use `test`/!/;
          SET TIMESTAMP=1565026349/!/;
          SET @@session.pseudo_thread_id=85/!/;
          SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/!/;
          SET @@session.sql_mode=1073741824/!/;
          SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/!/;
          /Unable to render embedded object: File (\C latin1 *//*) not found./;
          SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/!/;
          SET @@session.lc_time_names=0/!/;
          SET @@session.collation_database=DEFAULT/!/;
          CREATE TABLE t1 (a INT) ENGINE=INNODB
          /!/;

          1. at 231
            #190805 23:02:29 server id 1 end_log_pos 353 CRC32 0x74dc9dba Query thread_id=91 exec_time=0 error_code=0
            SET TIMESTAMP=1565026349/!/;
            SET @@session.pseudo_thread_id=91/!/;
            CREATE TEMPORARY TABLE t1 (b BLOB) ENGINE=INNODB
            /!/;
          2. at 353
            #190805 23:02:29 server id 1 end_log_pos 467 CRC32 0x375c73c3 Query thread_id=91 exec_time=0 error_code=0
            SET TIMESTAMP=1565026349/!/;
            /Unable to render embedded object: File (\C utf8 *//*) not found./;
            SET @@session.character_set_client=33,@@session.collation_connection=8,@@session.collation_server=8/!/;
            DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `t1`
            /!/;
          3. at 467
            #190805 23:02:29 server id 1 end_log_pos 582 CRC32 0xb1df765b Query thread_id=85 exec_time=0 error_code=0
            SET TIMESTAMP=1565026349/!/;
            SET @@session.pseudo_thread_id=85/!/;
            /Unable to render embedded object: File (\C latin1 *//*) not found./;
            SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/!/;
            DROP TABLE `t1` /* generated by server */
            /!/;
          4. at 582
            #190805 23:02:29 server id 1 end_log_pos 707 CRC32 0xe2f41c0e Query thread_id=91 exec_time=0 error_code=0
            SET TIMESTAMP=1565026349/!/;
            SET @@session.pseudo_thread_id=91/!/;
            DROP TEMPORARY TABLE `t1` /* generated by server */
            /!/;
          5. at 707

          ```
          The failure is not reproducible consistently. But at the time of failure the observation is an additional
          DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `t1` command is found in the 'bug28642318.sql' file.

          sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - ``` #190805 23:02:29 server id 1 end_log_pos 231 CRC32 0xf24eb6b3 Query thread_id=85 exec_time=0 error_code=0 use `test`/ ! /; SET TIMESTAMP=1565026349/ ! /; SET @@session.pseudo_thread_id=85/ ! /; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/ ! /; SET @@session.sql_mode=1073741824/ ! /; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/ ! /; / Unable to render embedded object: File (\C latin1 *//*) not found. /; SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/ ! /; SET @@session.lc_time_names=0/ ! /; SET @@session.collation_database=DEFAULT/ ! /; CREATE TABLE t1 (a INT) ENGINE=INNODB / ! /; at 231 #190805 23:02:29 server id 1 end_log_pos 353 CRC32 0x74dc9dba Query thread_id=91 exec_time=0 error_code=0 SET TIMESTAMP=1565026349/ ! /; SET @@session.pseudo_thread_id=91/ ! /; CREATE TEMPORARY TABLE t1 (b BLOB) ENGINE=INNODB / ! /; at 353 #190805 23:02:29 server id 1 end_log_pos 467 CRC32 0x375c73c3 Query thread_id=91 exec_time=0 error_code=0 SET TIMESTAMP=1565026349/ ! /; / Unable to render embedded object: File (\C utf8 *//*) not found. /; SET @@session.character_set_client=33,@@session.collation_connection=8,@@session.collation_server=8/ ! /; DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `t1` / ! /; at 467 #190805 23:02:29 server id 1 end_log_pos 582 CRC32 0xb1df765b Query thread_id=85 exec_time=0 error_code=0 SET TIMESTAMP=1565026349/ ! /; SET @@session.pseudo_thread_id=85/ ! /; / Unable to render embedded object: File (\C latin1 *//*) not found. /; SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/ ! /; DROP TABLE `t1` /* generated by server */ / ! /; at 582 #190805 23:02:29 server id 1 end_log_pos 707 CRC32 0xe2f41c0e Query thread_id=91 exec_time=0 error_code=0 SET TIMESTAMP=1565026349/ ! /; SET @@session.pseudo_thread_id=91/ ! /; DROP TEMPORARY TABLE `t1` /* generated by server */ / ! /; at 707 ``` The failure is not reproducible consistently. But at the time of failure the observation is an additional DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `t1` command is found in the 'bug28642318.sql' file.

          Hello Andrei,

          Can you please review the test fix.

          I manually verified that new test verifies the original bug report.
          Steps Performed:

          diff --git a/sql/sql_delete.cc b/sql/sql_delete.cc
          index ab02c3f9cca..dad2b5a0a11 100644
          --- a/sql/sql_delete.cc
          +++ b/sql/sql_delete.cc
          @@ -1324,7 +1324,7 @@ bool multi_delete::send_eof()
                   thd->clear_error();
                 else
                   errcode= query_error_code(thd, killed_status == NOT_KILLED);
          -      thd->thread_specific_used= TRUE;
          +     // thd->thread_specific_used= TRUE;
                 if (thd->binlog_query(THD::ROW_QUERY_TYPE,
                                       thd->query(), thd->query_length(),
                                       transactional_tables, FALSE, FALSE, errcode) &&
          
          

          Test output:

          worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
          binlog.binlog_stm_drop_tmp_tbl 'innodb_plugin,mix' [ fail ]
                  Test ended at 2019-08-21 15:52:00
           
          CURRENT_TEST: binlog.binlog_stm_drop_tmp_tbl
          ERROR 1137 (HY000) at line 57: Can't reopen table: 'd1'
          mysqltest: In included file "./extra/binlog_tests/drop_temp_table.test": 
          included from /home/sujatha/bug_repo/MDEV-20188-10.1/mysql-test/suite/binlog/t/binlog_stm_drop_tmp_tbl.test at line 6:
          At line 143: exec of '/home/sujatha/bug_repo/MDEV-20188-10.1/bld/client/mysql --defaults-file=/home/sujatha/bug_repo/MDEV-20188-10.1/bld/mysql-test/var/my.cnf < /home/sujatha/bug_repo/MDEV-20188-10.1/bld/mysql-test/var/tmp/bug28642318.sql' failed, error: 256, status: 1, errno: 95
          Output from before failure:
          # DELETE query fails with table re-open error without patch.
          

          Patch: https://github.com/MariaDB/server/commit/960604a7d16225ae001148346c6e100ca9dae969

          BuildBot test:http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-sujatha

          Thank you.

          sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - - edited Hello Andrei, Can you please review the test fix. I manually verified that new test verifies the original bug report. Steps Performed: diff --git a/sql/sql_delete.cc b/sql/sql_delete.cc index ab02c3f9cca..dad2b5a0a11 100644 --- a/sql/sql_delete.cc +++ b/sql/sql_delete.cc @@ -1324,7 +1324,7 @@ bool multi_delete::send_eof() thd->clear_error(); else errcode= query_error_code(thd, killed_status == NOT_KILLED); - thd->thread_specific_used= TRUE; + // thd->thread_specific_used= TRUE; if (thd->binlog_query(THD::ROW_QUERY_TYPE, thd->query(), thd->query_length(), transactional_tables, FALSE, FALSE, errcode) && Test output: worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019 binlog.binlog_stm_drop_tmp_tbl 'innodb_plugin,mix' [ fail ] Test ended at 2019-08-21 15:52:00   CURRENT_TEST: binlog.binlog_stm_drop_tmp_tbl ERROR 1137 (HY000) at line 57: Can't reopen table: 'd1' mysqltest: In included file "./extra/binlog_tests/drop_temp_table.test": included from /home/sujatha/bug_repo/MDEV-20188-10.1/mysql-test/suite/binlog/t/binlog_stm_drop_tmp_tbl.test at line 6: At line 143: exec of '/home/sujatha/bug_repo/MDEV-20188-10.1/bld/client/mysql --defaults-file=/home/sujatha/bug_repo/MDEV-20188-10.1/bld/mysql-test/var/my.cnf < /home/sujatha/bug_repo/MDEV-20188-10.1/bld/mysql-test/var/tmp/bug28642318.sql' failed, error: 256, status: 1, errno: 95 Output from before failure: # DELETE query fails with table re-open error without patch. Patch: https://github.com/MariaDB/server/commit/960604a7d16225ae001148346c6e100ca9dae969 BuildBot test: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-sujatha Thank you.
          Elkin Andrei Elkin added a comment -

          Salute, Sujatha.

          A question to

          what is this? Restoration after experimenting?

          Andrei

          –
          Andrei Elkin, Senior Software Developer
          MariaDB, Espoo, Finland, www.maria.com

          Elkin Andrei Elkin added a comment - Salute, Sujatha. A question to what is this? Restoration after experimenting? Andrei – Andrei Elkin, Senior Software Developer MariaDB, Espoo, Finland, www.maria.com
          sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - Fix for this issue is implemented in 10.1.42. 10.2 patch: https://github.com/MariaDB/server/commit/3ea242bb8af1144a7b5c3f64823017b81e485a12 10.3 patch: https://github.com/MariaDB/server/commit/fd8dd6531a1c90d90ef7808943cf89268a4254e1

          something similar fails on 5.5, but taking into account its time to live, I think it is OK

          sanja Oleksandr Byelkin added a comment - something similar fails on 5.5, but taking into account its time to live, I think it is OK

          People

            Elkin Andrei Elkin
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            4 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.