[MDEV-20188] binlog.binlog_stm_drop_tmp_tbl fails in buildbot with Unknown table on exec Created: 2019-07-26  Updated: 2020-03-06  Resolved: 2019-08-26

Status: Closed
Project: MariaDB Server
Component/s: Replication, Tests
Affects Version/s: 10.1, 10.2
Fix Version/s: 10.2.27, 10.1.42, 10.3.18, 10.4.8

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Andrei Elkin
Resolution: Fixed Votes: 0
Labels: regression, temporary-table-replication


 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.



 Comments   
Comment by Sujatha Sivakumar (Inactive) [ 2019-08-08 ]

```
#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.

Comment by Sujatha Sivakumar (Inactive) [ 2019-08-21 ]

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.

Comment by Andrei Elkin [ 2019-08-21 ]

Salute, Sujatha.

A question to

what is this? Restoration after experimenting?

Andrei


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

Comment by Sujatha Sivakumar (Inactive) [ 2019-08-26 ]

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

Comment by Oleksandr Byelkin [ 2020-03-06 ]

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

Generated at Thu Feb 08 08:57:30 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.