[MDEV-12887] UT_LIST_GET_LEN(trx->lock.trx_locks) == 0 when mysqldump sequence Created: 2017-05-24  Updated: 2018-02-19  Resolved: 2018-02-19

Status: Closed
Project: MariaDB Server
Component/s: Sequences, Storage Engine - InnoDB
Affects Version/s: 10.3.0
Fix Version/s: 10.3.1

Type: Bug Priority: Critical
Reporter: Andrii Nikitin (Inactive) Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None


 Description   

When trying to mysqldump database after "create sequence", InnoDB asserts like below:

$ mysql --defaults-file=my.cnf -e 'create sequence test.a'
$ mysqlsqldump --defaults-file=my.cnf test > /dev/null
mysqldump: Couldn't execute 'UNLOCK TABLES': Lost connection to MySQL server during query (2013)

2017-05-24  7:42:23 140019178026496 [Note] /home/a/test1/_depot/10.3-14465/bin/mysqld: ready for connections.
Version: '10.3.1-MariaDB'  socket: '/home/a/test1/mariadb-environs/m4-10.3~latest/dt/my.sock'  port: 3306  MariaDB Server
2017-05-24  7:42:53 140019102463744 [ERROR] Transaction not registered for MariaDB 2PC, but transaction is active
2017-05-24 07:42:53 0x7f58bcdd3700  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/storage/innobase/trx/trx0trx.cc line 1737
InnoDB: Failing assertion: UT_LIST_GET_LEN(trx->lock.trx_locks) == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
170524  7:42:53 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
 
Server version: 10.3.1-MariaDB
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=1
max_threads=153
thread_count=7
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467233 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f58480009a8
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x7f58bcdd2ec0 thread_stack 0x49000
/home/a/test1/mariadb-environs/m4-10.3~latest/../_depot/m-tar/10.3-14465/bin/mysqld(my_print_stacktrace+0x2b)[0x5581a4bcd4db]
/home/a/test1/mariadb-environs/m4-10.3~latest/../_depot/m-tar/10.3-14465/bin/mysqld(handle_fatal_signal+0x4d5)[0x5581a4661af5]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11630)[0x7f58c098e630]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x9f)[0x7f58bff5a7ef]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f58bff5c3ea]
/home/a/test1/mariadb-environs/m4-10.3~latest/../_depot/m-tar/10.3-14465/bin/mysqld(+0x4a2048)[0x5581a4409048]
/home/a/test1/mariadb-environs/m4-10.3~latest/../_depot/m-tar/10.3-14465/bin/mysqld(+0x9cfcf9)[0x5581a4936cf9]
/home/a/test1/mariadb-environs/m4-10.3~latest/../_depot/m-tar/10.3-14465/bin/mysqld(+0x9cff9a)[0x5581a4936f9a]
mysys/stacktrace.c:268(my_print_stacktrace)[0x5581a49371a7]
ut/ut0rbt.cc:459(rbt_eject_node(ib_rbt_node_t*, ib_rbt_node_t*) [clone .part.4])[0x5581a47c6bf1]
handler/ha_innodb.cc:4571(innobase_commit_low(trx_t*))[0x5581a47c6e8a]
handler/ha_innodb.cc:4707(innobase_commit_ordered_2(trx_t*, THD*))[0x5581a47d95f3]
handler/ha_innodb.cc:16526(ha_innobase::external_lock(THD*, int))[0x5581a47db4d5]
sql/ha_sequence.cc:320(ha_sequence::external_lock(THD*, int))[0x5581a4ba9205]
sql/handler.cc:5891(handler::ha_external_lock(THD*, int))[0x5581a466b00c]
sql/lock.cc:716(unlock_external(THD*, TABLE**, unsigned int))[0x5581a47252fb]
sql/lock.cc:428(mysql_unlock_tables(THD*, st_mysql_lock*, bool))[0x5581a47254ab]
sql/sql_base.cc:841(close_thread_tables(THD*))[0x5581a4474f87]
sql/sql_base.cc:2171(Locked_tables_list::unlock_locked_tables(THD*))[0x5581a44758da]
sql/sql_parse.cc:4979(mysql_execute_command(THD*))[0x5581a44c2d8c]
sql/sql_parse.cc:7912(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x5581a44c575a]
sql/sql_parse.cc:1817(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x5581a44c79ca]
sql/sql_parse.cc:1382(do_command(THD*))[0x5581a44c7f91]
sql/sql_connect.cc:1354(do_handle_one_connection(CONNECT*))[0x5581a45840ef]
sql/sql_connect.cc:1262(handle_one_connection)[0x5581a4584214]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ca)[0x7f58c09846ca]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x5f)[0x7f58c002d0af]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7f58480111b0): UNLOCK TABLES
Connection ID (thread ID): 10
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.



 Comments   
Comment by Andrii Nikitin (Inactive) [ 2017-05-24 ]

The crash happens if default_storage_engine is set to default (InnoDB) (during sequence creation) and doesn't happen when default_storage_engine is myisam.

Comment by Elena Stepanova [ 2017-05-24 ]

anikitin,

Please extract relevant parameters (if any) from the mentioned but not provided my.cnf, and put them on the command line along with --no-defaults.

Comment by Andrii Nikitin (Inactive) [ 2017-05-24 ]

$ mysqldump --no-defaults --port=3309 --host=127.0.0.1 test > /dev/null
mysqldump: Couldn't execute 'UNLOCK TABLES': Lost connection to MySQL server during query (2013)

Comment by Elena Stepanova [ 2017-05-24 ]

Actual test case:

--source include/have_innodb.inc
set default_storage_engine=InnoDB;
create sequence a;
LOCK TABLES a READ;
SELECT * FROM a;

bb-10.2-ext debug 90f06818b3250fd44aff4235875c7b6dd6ba8041

mysqld: /data/src/bb-10.2-ext/storage/innobase/lock/lock0lock.cc:4337: ib_lock_t* lock_table_create(ib_lock_t*, dict_table_t*, ulint, trx_t*): Assertion `!(((trx))->auto_commit && ((trx))->will_lock == 0)' failed.
170524 15:35:42 [ERROR] mysqld got signal 6 ;
 
#7  0x00007feef797eee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x00007feefa7439d6 in lock_table_create (c_lock=0x0, table=0x7feea000c0b8, type_mode=0, trx=0x7feef1a988c8) at /data/src/bb-10.2-ext/storage/innobase/lock/lock0lock.cc:4337
#9  0x00007feefa7441fd in lock_table_create (table=0x7feea000c0b8, type_mode=0, trx=0x7feef1a988c8) at /data/src/bb-10.2-ext/storage/innobase/lock/lock0lock.cc:4448
#10 0x00007feefa745043 in lock_table (flags=0, table=0x7feea000c0b8, mode=LOCK_IS, thr=0x7feea00dac70) at /data/src/bb-10.2-ext/storage/innobase/lock/lock0lock.cc:4793
#11 0x00007feefa83f69e in row_search_mvcc (buf=0x7feea00973b8 "\377", '\245' <repeats 63 times>, "\377", '\245' <repeats 63 times>, "\200t\t\240\356\177", mode=PAGE_CUR_G, prebuilt=0x7feea00da438, match_mode=0, direction=0) at /data/src/bb-10.2-ext/storage/innobase/row/row0sel.cc:4549
#12 0x00007feefa6cbf47 in ha_innobase::index_read (this=0x7feea009bae8, buf=0x7feea00973b8 "\377", '\245' <repeats 63 times>, "\377", '\245' <repeats 63 times>, "\200t\t\240\356\177", key_ptr=0x0, key_len=0, find_flag=HA_READ_AFTER_KEY) at /data/src/bb-10.2-ext/storage/innobase/handler/ha_innodb.cc:10004
#13 0x00007feefa6cd242 in ha_innobase::index_first (this=0x7feea009bae8, buf=0x7feea00973b8 "\377", '\245' <repeats 63 times>, "\377", '\245' <repeats 63 times>, "\200t\t\240\356\177") at /data/src/bb-10.2-ext/storage/innobase/handler/ha_innodb.cc:10432
#14 0x00007feefa6cd49f in ha_innobase::rnd_next (this=0x7feea009bae8, buf=0x7feea00973b8 "\377", '\245' <repeats 63 times>, "\377", '\245' <repeats 63 times>, "\200t\t\240\356\177") at /data/src/bb-10.2-ext/storage/innobase/handler/ha_innodb.cc:10526
#15 0x00007feefaaee39a in ha_sequence::rnd_next (this=0x7feea00f39a8, buf=0x7feea00973b8 "\377", '\245' <repeats 63 times>, "\377", '\245' <repeats 63 times>, "\200t\t\240\356\177") at /data/src/bb-10.2-ext/sql/ha_sequence.h:97
#16 0x00007feefa3b8d0d in handler::ha_rnd_next (this=0x7feea00f39a8, buf=0x7feea00973b8 "\377", '\245' <repeats 63 times>, "\377", '\245' <repeats 63 times>, "\200t\t\240\356\177") at /data/src/bb-10.2-ext/sql/handler.cc:2594
#17 0x00007feefa3ba487 in handler::read_first_row (this=0x7feea00f39a8, buf=0x7feea00973b8 "\377", '\245' <repeats 63 times>, "\377", '\245' <repeats 63 times>, "\200t\t\240\356\177", primary_key=64) at /data/src/bb-10.2-ext/sql/handler.cc:2831
#18 0x00007feefa18ce09 in handler::ha_read_first_row (this=0x7feea00f39a8, buf=0x7feea00973b8 "\377", '\245' <repeats 63 times>, "\377", '\245' <repeats 63 times>, "\200t\t\240\356\177", primary_key=64) at /data/src/bb-10.2-ext/sql/sql_class.h:5822
#19 0x00007feefa1760a1 in join_read_system (tab=0x7feea0013ef0) at /data/src/bb-10.2-ext/sql/sql_select.cc:18960
#20 0x00007feefa175c62 in join_read_const_table (thd=0x7feea0000b00, tab=0x7feea0013ef0, pos=0x7feea00144a8) at /data/src/bb-10.2-ext/sql/sql_select.cc:18856
#21 0x00007feefa1507f8 in make_join_statistics (join=0x7feea0012e50, tables_list=..., keyuse_array=0x7feea0013138) at /data/src/bb-10.2-ext/sql/sql_select.cc:3997
#22 0x00007feefa147ebc in JOIN::optimize_inner (this=0x7feea0012e50) at /data/src/bb-10.2-ext/sql/sql_select.cc:1506
#23 0x00007feefa1466eb in JOIN::optimize (this=0x7feea0012e50) at /data/src/bb-10.2-ext/sql/sql_select.cc:1085
#24 0x00007feefa14f5ce in mysql_select (thd=0x7feea0000b00, tables=0x7feea0012778, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2149845760, result=0x7feea0012e30, unit=0x7feea0004688, select_lex=0x7feea0004dc8) at /data/src/bb-10.2-ext/sql/sql_select.cc:3657
#25 0x00007feefa144010 in handle_select (thd=0x7feea0000b00, lex=0x7feea00045c0, result=0x7feea0012e30, setup_tables_done_option=0) at /data/src/bb-10.2-ext/sql/sql_select.cc:373
#26 0x00007feefa110658 in execute_sqlcom_select (thd=0x7feea0000b00, all_tables=0x7feea0012778) at /data/src/bb-10.2-ext/sql/sql_parse.cc:6459
#27 0x00007feefa106a1b in mysql_execute_command (thd=0x7feea0000b00) at /data/src/bb-10.2-ext/sql/sql_parse.cc:3581
#28 0x00007feefa114078 in mysql_parse (thd=0x7feea0000b00, rawbuf=0x7feea0012598 "SELECT * FROM a", length=15, parser_state=0x7feee8763200, is_com_multi=false, is_next_command=false) at /data/src/bb-10.2-ext/sql/sql_parse.cc:7912
#29 0x00007feefa101d97 in dispatch_command (command=COM_QUERY, thd=0x7feea0000b00, packet=0x7feea00ef901 "SELECT * FROM a", packet_length=15, is_com_multi=false, is_next_command=false) at /data/src/bb-10.2-ext/sql/sql_parse.cc:1817
#30 0x00007feefa100740 in do_command (thd=0x7feea0000b00) at /data/src/bb-10.2-ext/sql/sql_parse.cc:1380
#31 0x00007feefa24d62a in do_handle_one_connection (connect=0x7feefdf14590) at /data/src/bb-10.2-ext/sql/sql_connect.cc:1354
#32 0x00007feefa24d3b7 in handle_one_connection (arg=0x7feefdf14590) at /data/src/bb-10.2-ext/sql/sql_connect.cc:1260
#33 0x00007feefa6a879e in pfs_spawn_thread (arg=0x7feefdfb77c0) at /data/src/bb-10.2-ext/storage/perfschema/pfs.cc:1862
#34 0x00007feef96b8494 in start_thread (arg=0x7feee8764700) at pthread_create.c:333
#35 0x00007feef7a3b93f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Comment by Michael Widenius [ 2018-02-19 ]

This was fixed already on May 24'th independently of this bug report and because of this
I missed to close this bug.

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