[MDEV-19840] Assertion `m_status == DA_ERROR' failed in Diagnostics_area::sql_errno upon SELECT from I_S with concurrent locking Created: 2019-06-23  Updated: 2023-04-27

Status: Open
Project: MariaDB Server
Component/s: Admin statements, Locking, Sequences
Affects Version/s: 10.3, 10.4, 10.5
Fix Version/s: 10.4, 10.5

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Rucha Deodhar
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-14836 Assertion `m_status == DA_ERROR' fail... Closed
relates to MDEV-19555 sql/sql_error.h:1036: uint Diagnostic... Closed
relates to MDEV-22266 Diagnostics_area::sql_errno() const: ... Closed

 Description   

NOTES:

  • The test case is for reproducing purposes only, don't put it into the regression suite!
  • The test case has a loop of 100 attempts. It appears to be enough for me, usually it fails within first 50, but it can vary on different machines and builds. Increase it if it's not enough. It can also be done via usual --repeat, but it will be slower.
  • The test case has a little bit of everything – sequences, backup locks, etc., so it's not applicable to previous versions, thus it hasn't been checked on versions other than 10.4, and I'm not sure to which component it really belongs.
  • I've added to the test case some protection against other sporadic failures. Timeouts are probably expected, but also DROP SEQUENCE and CREATE SEQUENCE sometimes fail due to "sequence doesn't exist" and "sequence already exists". It's probably a problem in itself.
  • Even now, the test case sometimes fails with

    connect  con1,localhost,root,,test;
    CREATE SEQUENCE IF NOT EXISTS s ENGINE=InnoDB;
    bug.2965a 'innodb'                       [ fail ]
            Test ended at 2019-06-23 19:11:29
     
    CURRENT_TEST: bug.2965a
    mysqltest: At line 47: query 'CREATE SEQUENCE IF NOT EXISTS s ENGINE=InnoDB' failed: 1813: Tablespace for table '`test`.`s`' exists. Please DISCARD the tablespace before IMPORT
    

    I don't want to complicate the test case further by hiding it, besides, something is definitely wrong when it happens, so it requires attention as well. I'm not sure whether it is related to the main complaint in this report or not.

  • Might be related to MDEV-19555, but I couldn't make this one fail on CHECK, so I'm filing it separately.

--source include/have_innodb.inc
 
--let $run= 100
 
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
CREATE TABLE t2 (b INT) ENGINE=InnoDB;
CREATE TABLE t3 (c INT) ENGINE=InnoDB;
CREATE TABLE t4 (d INT) ENGINE=InnoDB;
CREATE TABLE t5 (e INT) ENGINE=InnoDB;
 
while ($run)
{
    --echo #
    --echo # $run rounds left
    --connection default
    BEGIN;
    SELECT * FROM t4;
 
    --connect (con1,localhost,root,,test)
    CREATE SEQUENCE IF NOT EXISTS s ENGINE=InnoDB;
    --connection default
    --error ER_BAD_FIELD_ERROR
    UPDATE t2 SET x = 0;
    --connection default
    --send
      SELECT * FROM information_schema.tables;
    --connection con1
    SET lock_wait_timeout= 1;
    --send
      LOCK TABLE t3 READ, t5 WRITE, t2 READ;
    --connect (con2,localhost,root,,test)
    SET lock_wait_timeout= 1;
    BACKUP STAGE START;
    --error 0,ER_LOCK_WAIT_TIMEOUT
    BACKUP STAGE BLOCK_COMMIT;
 
    # Cleanup
    --disconnect con2
    --connection default
    --reap
    DROP SEQUENCE IF EXISTS s;
    --connection con1
    --error 0,ER_LOCK_WAIT_TIMEOUT
    --reap
    --disconnect con1
    --dec $run
}
--connection default
DROP TABLE IF EXISTS t1, t3, t2, t4, t5;

a82e42fd

mysqld: /data/src/10.4/sql/sql_error.h:1036: uint Diagnostics_area::sql_errno() const: Assertion `m_status == DA_ERROR' failed.
190623 19:12:25 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f22d8caff12 in __GI___assert_fail (assertion=0x55d4bd81ac94 "m_status == DA_ERROR", file=0x55d4bd81ac00 "/data/src/10.4/sql/sql_error.h", line=1036, function=0x55d4bd81b7c0 <Diagnostics_area::sql_errno() const::__PRETTY_FUNCTION__> "uint Diagnostics_area::sql_errno() const") at assert.c:101
#8  0x000055d4bcb2c4e4 in Diagnostics_area::sql_errno (this=0x7f22880064b8) at /data/src/10.4/sql/sql_error.h:1036
#9  0x000055d4bcf8389a in ha_rollback_trans (thd=0x7f2288000b00, all=true) at /data/src/10.4/sql/handler.cc:1919
#10 0x000055d4bcdcfc3b in trans_rollback_implicit (thd=0x7f2288000b00) at /data/src/10.4/sql/transaction.cc:387
#11 0x000055d4bcc4f13d in mysql_execute_command (thd=0x7f2288000b00) at /data/src/10.4/sql/sql_parse.cc:6169
#12 0x000055d4bcc53cdb in mysql_parse (thd=0x7f2288000b00, rawbuf=0x7f2288013108 "SELECT * FROM information_schema.tables", length=39, parser_state=0x7f22ce070180, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7892
#13 0x000055d4bcc3ff85 in dispatch_command (command=COM_QUERY, thd=0x7f2288000b00, packet=0x7f2288137ba1 "0\001Y\247", packet_length=39, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1827
#14 0x000055d4bcc3e743 in do_command (thd=0x7f2288000b00) at /data/src/10.4/sql/sql_parse.cc:1360
#15 0x000055d4bcdb7993 in do_handle_one_connection (connect=0x55d4bfc6fdd0) at /data/src/10.4/sql/sql_connect.cc:1403
#16 0x000055d4bcdb76f7 in handle_one_connection (arg=0x55d4bfc6fdd0) at /data/src/10.4/sql/sql_connect.cc:1306
#17 0x000055d4bd6e2e49 in pfs_spawn_thread (arg=0x55d4bfbee760) at /data/src/10.4/storage/perfschema/pfs.cc:1862
#18 0x00007f22da8244a4 in start_thread (arg=0x7f22ce071700) at pthread_create.c:456
#19 0x00007f22d8d6cd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

No obvious effect on a non-debug build, but there is no guarantee at all, given how non-deterministic the test is.



 Comments   
Comment by Elena Stepanova [ 2020-07-26 ]

An alternative test case which doesn't involve backup locks, but involves XA instead. It makes it applicable to 10.3 as well, and it fails there (run with --repeat=N if it doesn't fail right away).

--source include/have_innodb.inc
 
# Not sure why restart is important,
# probably has something to do with MTR checks before a test case
--source include/restart_mysqld.inc
 
CREATE TABLE t1 (pk INT AUTO_INCREMENT PRIMARY KEY, a INT) ENGINE=InnoDB;
XA BEGIN 'x';
SELECT * FROM t1;
 
--connect (con1,localhost,root,,test)
CREATE SEQUENCE s MAXVALUE = 10000 ENGINE=InnoDB;
 
--connection default
--send
  SELECT * FROM mysql.db JOIN INFORMATION_SCHEMA.TABLES ON (VERSION = 0);
 
--connection con1
FLUSH TABLES WITH READ LOCK;
UNLOCK TABLES;
--disconnect con1
 
--connection default
--reap
 
# Cleanup
XA END 'x';
XA ROLLBACK 'x';
DROP TABLE t1;
DROP SEQUENCE s;

10.3 1656ea28

mysqld: /data/src/10.3/sql/sql_error.h:1005: uint Diagnostics_area::sql_errno() const: Assertion `m_status == DA_ERROR' failed.
200726 15:53:31 [ERROR] mysqld got signal 6 ;
 
Query (0x7f6660014918): SELECT * FROM mysql.db JOIN INFORMATION_SCHEMA.TABLES ON (VERSION = 0)
Connection ID (thread ID): 8
Status: NOT_KILLED

#7  0x00007f66b256cf12 in __GI___assert_fail (assertion=0x55870e7186f4 "m_status == DA_ERROR", file=0x55870e7186a8 "/data/src/10.3/sql/sql_error.h", line=1005, function=0x55870e7195c0 <Diagnostics_area::sql_errno() const::__PRETTY_FUNCTION__> "uint Diagnostics_area::sql_errno() const") at assert.c:101
#8  0x000055870d9c927a in Diagnostics_area::sql_errno (this=0x7f6660006088) at /data/src/10.3/sql/sql_error.h:1005
#9  0x000055870ddfadf1 in ha_rollback_trans (thd=0x7f6660000af0, all=true) at /data/src/10.3/sql/handler.cc:1773
#10 0x000055870dc639aa in trans_rollback_implicit (thd=0x7f6660000af0) at /data/src/10.3/sql/transaction.cc:454
#11 0x000055870dae4f68 in mysql_execute_command (thd=0x7f6660000af0) at /data/src/10.3/sql/sql_parse.cc:6131
#12 0x000055870dae9f61 in mysql_parse (thd=0x7f6660000af0, rawbuf=0x7f6660014918 "SELECT * FROM mysql.db JOIN INFORMATION_SCHEMA.TABLES ON (VERSION = 0)", length=70, parser_state=0x7f66ac16a5e0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7810
#13 0x000055870dad67a8 in dispatch_command (command=COM_QUERY, thd=0x7f6660000af0, packet=0x7f6660008c71 "", packet_length=70, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1848
#14 0x000055870dad50c0 in do_command (thd=0x7f6660000af0) at /data/src/10.3/sql/sql_parse.cc:1393
#15 0x000055870dc4e693 in do_handle_one_connection (connect=0x5587111d4f60) at /data/src/10.3/sql/sql_connect.cc:1403
#16 0x000055870dc4e3f5 in handle_one_connection (arg=0x5587111d4f60) at /data/src/10.3/sql/sql_connect.cc:1308
#17 0x000055870e6062f2 in pfs_spawn_thread (arg=0x5587111effc0) at /data/src/10.3/storage/perfschema/pfs.cc:1869
#18 0x00007f66b44f54a4 in start_thread (arg=0x7f66ac16b700) at pthread_create.c:456
#19 0x00007f66b2629d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

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