[MDEV-21822] InnoDB: Failing assertion: UT_LIST_GET_LEN(trx->lock.trx_locks) == 0 upon trivial SELECT from InnoDB table after wrong operations with sequences Created: 2020-02-26  Updated: 2020-06-08  Resolved: 2020-06-08

Status: Closed
Project: MariaDB Server
Component/s: Locking, Sequences, Storage Engine - InnoDB
Affects Version/s: 10.5
Fix Version/s: 10.3.24

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Duplicate Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-19544 Remove innodb_locks_unsafe_for_binlog Closed
relates to MDEV-19977 Assertion `(0xFUL & mode) == LOCK_S |... Closed
relates to MDEV-20870 InnoDB: Assertion failure in file /ho... Closed

 Description    

--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
 
CREATE SEQUENCE s ENGINE=InnoDB;
 
ALTER IGNORE TABLE s ADD CONSTRAINT CHECK (start_value > 1);
 
--error 0,ER_KEY_NOT_FOUND
 
SHOW CREATE SEQUENCE s;
 
SELECT * FROM t1;
 
 
 
# Cleanup
 
DROP SEQUENCE s;
 
DROP TABLE t1;

On a non-debug build, the problem starts with ER_KEY_NOT_FOUND upon SHOW CREATE SEQUENCE which shouldn't be happening. The test case suppresses the error to get to the assertion failure below.
The debug build fails instead with MDEV-19977 upon SHOW CREATE SEQUENCE.

10.5 non-debug 9894751a

 
2020-02-27 01:12:43 0x7f8ffc241700  InnoDB: Assertion failure in file /data/src/10.5/storage/innobase/trx/trx0trx.cc line 1348
 
InnoDB: Failing assertion: UT_LIST_GET_LEN(trx->lock.trx_locks) == 0
 
 
 
#6  0x000055eced651b29 in ut_dbg_assertion_failed (expr=expr@entry=0x55ecee0ba170 "UT_LIST_GET_LEN(trx->lock.trx_locks) == 0", file=file@entry=0x55ecee0b9fc0 "/data/src/10.5/storage/innobase/trx/trx0trx.cc", line=line@entry=1348) at /data/src/10.5/storage/innobase/ut/ut0dbg.cc:60
 
#7  0x000055ecedcd9da0 in trx_commit_in_memory (mtr=<optimized out>, trx=<optimized out>) at /data/src/10.5/storage/innobase/trx/trx0trx.cc:1348
 
#8  trx_commit_low (trx=<optimized out>, mtr=<optimized out>) at /data/src/10.5/storage/innobase/trx/trx0trx.cc:1601
 
#9  0x000055ecedcda394 in trx_commit (trx=trx@entry=0x7f8ffc4ee0b0) at /data/src/10.5/storage/innobase/trx/trx0trx.cc:1625
 
#10 0x000055ecedcda5a8 in trx_commit_for_mysql (trx=trx@entry=0x7f8ffc4ee0b0) at /data/src/10.5/storage/innobase/trx/trx0trx.cc:1771
 
#11 0x000055ecedbac0dd in innobase_commit_low (trx=trx@entry=0x7f8ffc4ee0b0) at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:4138
 
#12 0x000055ecedbac294 in innobase_commit_ordered_2 (trx=trx@entry=0x7f8ffc4ee0b0, thd=thd@entry=0x7f8fc00009a8) at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:4260
 
#13 0x000055ecedbac57b in innobase_commit (hton=<optimized out>, thd=thd@entry=0x7f8fc00009a8, commit_trx=commit_trx@entry=true) at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:4376
 
#14 0x000055ecedbb4d9f in ha_innobase::external_lock (this=0x7f8fc0080140, thd=0x7f8fc00009a8, lock_type=2) at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:16065
 
#15 0x000055eced92f7c5 in handler::ha_external_lock (this=0x7f8fc0080140, thd=thd@entry=0x7f8fc00009a8, lock_type=lock_type@entry=2) at /data/src/10.5/sql/handler.cc:6392
 
#16 0x000055eced9ff1e7 in unlock_external (thd=0x7f8fc00009a8, table=0x7f8fc0011678, count=<optimized out>) at /data/src/10.5/sql/lock.cc:709
 
#17 0x000055eced9ff9c0 in mysql_unlock_read_tables (thd=<optimized out>, sql_lock=0x7f8fc0011658) at /data/src/10.5/sql/lock.cc:485
 
#18 0x000055eced7898ba in JOIN::join_free (this=this@entry=0x7f8fc0011728) at /data/src/10.5/sql/sql_select.cc:13703
 
#19 0x000055eced7a1f56 in do_select (procedure=<optimized out>, join=0x7f8fc0011728) at /data/src/10.5/sql/sql_select.cc:20039
 
#20 JOIN::exec_inner (this=this@entry=0x7f8fc0011728) at /data/src/10.5/sql/sql_select.cc:4457
 
#21 0x000055eced7a2227 in JOIN::exec (this=this@entry=0x7f8fc0011728) at /data/src/10.5/sql/sql_select.cc:4238
 
#22 0x000055eced7a0600 in mysql_select (thd=thd@entry=0x7f8fc00009a8, tables=0x7f8fc00106d0, fields=..., conds=0x0, og_num=<optimized out>, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7f8fc0011700, unit=0x7f8fc0004730, select_lex=0x7f8fc00100d8) at /data/src/10.5/sql/sql_select.cc:4662
 
#23 0x000055eced7a0f7c in handle_select (thd=thd@entry=0x7f8fc00009a8, lex=lex@entry=0x7f8fc0004670, result=result@entry=0x7f8fc0011700, setup_tables_done_option=setup_tables_done_option@entry=0) at /data/src/10.5/sql/sql_select.cc:428
 
#24 0x000055eced641c1f in execute_sqlcom_select (thd=thd@entry=0x7f8fc00009a8, all_tables=0x7f8fc00106d0) at /data/src/10.5/sql/sql_parse.cc:6138
 
#25 0x000055eced747584 in mysql_execute_command (thd=thd@entry=0x7f8fc00009a8) at /data/src/10.5/sql/sql_parse.cc:3904
 
#26 0x000055eced74e9db in mysql_parse (thd=thd@entry=0x7f8fc00009a8, rawbuf=<optimized out>, length=16, parser_state=parser_state@entry=0x7f8ffc240590, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.5/sql/sql_parse.cc:7918
 
#27 0x000055eced743f54 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f8fc00009a8, packet=packet@entry=0x7f8fc0007aa9 "", packet_length=packet_length@entry=16, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.5/sql/sql_parse.cc:1845
 
#28 0x000055eced742853 in do_command (thd=0x7f8fc00009a8) at /data/src/10.5/sql/sql_parse.cc:1364
 
#29 0x000055eced82a1a4 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55ecf05e2878, put_in_cache=put_in_cache@entry=true) at /data/src/10.5/sql/sql_connect.cc:1422
 
#30 0x000055eced82a4e2 in handle_one_connection (arg=arg@entry=0x55ecf05e2878) at /data/src/10.5/sql/sql_connect.cc:1319
 
#31 0x000055ecedb62be4 in pfs_spawn_thread (arg=0x55ecf05e28d8) at /data/src/10.5/storage/perfschema/pfs.cc:1869
 
#32 0x00007f9003e354a4 in start_thread (arg=0x7f8ffc241700) at pthread_create.c:456
 
#33 0x00007f9001f69d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

The problem appeared in 10.5 tree after this commit:

commit 1a6f470464171bd1144e4dd6f169bb4018f2e81a
 
Author: Marko Mäkelä
 
Date:   Wed May 22 14:49:38 2019 +0300
 
 
 
    MDEV-19544 Remove innodb_locks_unsafe_for_binlog
 
    
    The transaction isolation levels READ COMMITTED and READ UNCOMMITTED
 
    should behave similarly to the old deprecated setting
 
    innodb_locks_unsafe_for_binlog=1, that is, avoid acquiring gap locks.
 
    
    row_search_mvcc(): Reduce the scope of some variables, and clean up
 
    the initialization and use of the variable set_also_gap_locks.

However, I don't know whether it actually introduced the problem or just made it more visible. We have an external report MDEV-20870 about the same assertion failure, but it happened on 10.4. Maybe it had a totally different cause, or maybe the underlying issue is the same.

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

Assigned to svoj because it's complementary to MDEV-19977.

Comment by Elena Stepanova [ 2020-05-15 ]

The assertion looks a bit differently now (same test case):

10.5 3b251e24

 
2020-05-15 18:23:13 0x7fbb980d9700  InnoDB: Assertion failure in file /data/src/10.5/storage/innobase/trx/trx0trx.cc line 1340
 
InnoDB: Failing assertion: UT_LIST_GET_LEN(lock.trx_locks) == 0
 
 
 
#5  0x00007fa914dd702a in __GI_abort () at abort.c:89
 
#6  0x0000564fc1c5d460 in ut_dbg_assertion_failed (expr=expr@entry=0x564fc26b0c70 "UT_LIST_GET_LEN(lock.trx_locks) == 0", file=file@entry=0x564fc26b09f8 "/home/vsts/src/storage/innobase/trx/trx0trx.cc", line=line@entry=1340) at /home/vsts/src/storage/innobase/ut/ut0dbg.cc:60
 
#7  0x0000564fc22eb478 in trx_t::commit_in_memory (mtr=<optimized out>, this=<optimized out>) at /home/vsts/src/storage/innobase/trx/trx0trx.cc:1340
 
#8  trx_t::commit_low (this=<optimized out>, mtr=<optimized out>) at /home/vsts/src/storage/innobase/trx/trx0trx.cc:1562
 
#9  0x0000564fc22eb9f4 in trx_t::commit (this=this@entry=0x7fa9141603f0) at /home/vsts/src/storage/innobase/trx/trx0trx.cc:1576
 
#10 0x0000564fc22ebbe8 in trx_commit_for_mysql (trx=trx@entry=0x7fa9141603f0) at /home/vsts/src/storage/innobase/trx/trx0trx.cc:1708
 
#11 0x0000564fc21b39c8 in innobase_commit_low (trx=trx@entry=0x7fa9141603f0) at /home/vsts/src/storage/innobase/handler/ha_innodb.cc:4125
 
#12 0x0000564fc21b3bce in innobase_commit_ordered_2 (trx=trx@entry=0x7fa9141603f0, thd=thd@entry=0x7fa8ad1d4948) at /home/vsts/src/storage/innobase/handler/ha_innodb.cc:4254
 
#13 0x0000564fc21b3ea3 in innobase_commit (hton=<optimized out>, thd=0x7fa8ad1d4948, commit_trx=<optimized out>) at /home/vsts/src/storage/innobase/handler/ha_innodb.cc:4371
 
#14 0x0000564fc1f37825 in commit_one_phase_2 (thd=thd@entry=0x7fa8ad1d4948, all=false, trans=0x7fa8ad1d7d98, is_real_trans=true) at /home/vsts/src/sql/handler.cc:1879
 
#15 0x0000564fc1f39b97 in ha_commit_one_phase (thd=thd@entry=0x7fa8ad1d4948, all=all@entry=false) at /home/vsts/src/sql/handler.cc:1859
 
#16 0x0000564fc1f3a4d7 in ha_commit_trans (thd=thd@entry=0x7fa8ad1d4948, all=all@entry=false) at /home/vsts/src/sql/handler.cc:1659
 
#17 0x0000564fc1e474cb in trans_commit_stmt (thd=thd@entry=0x7fa8ad1d4948) at /home/vsts/src/sql/transaction.cc:463
 
#18 0x0000564fc1d54325 in mysql_execute_command (thd=thd@entry=0x7fa8ad1d4948) at /home/vsts/src/sql/sql_parse.cc:5971
 
#19 0x0000564fc1d5b16b in mysql_parse (thd=thd@entry=0x7fa8ad1d4948, rawbuf=<optimized out>, length=94, parser_state=parser_state@entry=0x7fa8fd58f520, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /home/vsts/src/sql/sql_parse.cc:7957
 
#20 0x0000564fc1d51aeb in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fa8ad1d4948, packet=packet@entry=0x7fa8ad427589 "SELECT /* QNO 56894 CON_ID 11 */ `from`, `to` INTO @tm1, @tm2 FROM ts8 ORDER BY `from` LIMIT 1 ", packet_length=packet_length@entry=95, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /home/vsts/src/sql/sql_parse.cc:1840
 
#21 0x0000564fc1d500a3 in do_command (thd=0x7fa8ad1d4948) at /home/vsts/src/sql/sql_parse.cc:1359
 
#22 0x0000564fc1e38fcc in do_handle_one_connection (connect=<optimized out>, connect@entry=0x564fc621dd28, put_in_cache=put_in_cache@entry=true) at /home/vsts/src/sql/sql_connect.cc:1411
 
#23 0x0000564fc1e39553 in handle_one_connection (arg=arg@entry=0x564fc621dd28) at /home/vsts/src/sql/sql_connect.cc:1313
 
#24 0x0000564fc2128404 in pfs_spawn_thread (arg=0x564fc62b4c38) at /home/vsts/src/storage/perfschema/pfs.cc:2201
 
#25 0x00007fa915c796ba in start_thread (arg=0x7fa8fd590700) at pthread_create.c:333
 
#26 0x00007fa914ea741d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Comment by Michael Widenius [ 2020-06-08 ]

Duplicate of MDEV-19977 which is already pushed into 10.3 tree

Generated at Thu Feb 08 09:10:04 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.