[MDEV-17210] InnoDB: Assertion failure in file lock0lock.cc: 6392 Created: 2018-09-17  Updated: 2018-11-15  Resolved: 2018-11-15

Status: Closed
Project: MariaDB Server
Component/s: Galera, Tests
Affects Version/s: 10.3
Fix Version/s: 10.3.11

Type: Bug Priority: Critical
Reporter: Jan Lindström (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Blocks
blocks MDEV-13549 Galera 3 test failures Closed

 Description    

0.3 galera_many_rows 
#7 0x00007f6d750dfb02 in __GI___assert_fail (assertion=0x555cca242796 "!is_owned()", file=0x555cca242760 "/mariadb/10.3/storage/innobase/include/sync0policy.ic", line=64, function=0x555cca243180 <MutexDebug<TTASEventMutex<GenericPolicy> >::enter(TTASEventMutex<GenericPolicy> const*, char const*, unsigned int)::__PRETTY_FUNCTION__> "void MutexDebug<Mutex>::enter(const Mutex*, const char*, unsigned int) [with Mutex = TTASEventMutex<GenericPolicy>]") at assert.c:101
 
#8 0x0000555cc9a5c01d in MutexDebug<TTASEventMutex<GenericPolicy> >::enter (this=0x555ccaa68390 <lock_sys+80>, mutex=0x555ccaa68380 <lock_sys+64>, name=0x555cca25d898 "/mariadb/10.3/storage/innobase/lock/lock0lock.cc", line=6392) at /mariadb/10.3/storage/innobase/include/sync0policy.ic:64
 
#9 0x0000555cc9a5b1f8 in GenericPolicy<TTASEventMutex<GenericPolicy> >::enter (this=0x555ccaa68390 <lock_sys+80>, mutex=..., filename=0x555cca25d898 "/mariadb/10.3/storage/innobase/lock/lock0lock.cc", line=6392) at /mariadb/10.3/storage/innobase/include/sync0policy.h:347
 
#10 0x0000555cc9a5983c in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (this=0x555ccaa68380 <lock_sys+64>, n_spins=30, n_delay=4, name=0x555cca25d898 "/mariadb/10.3/storage/innobase/lock/lock0lock.cc", line=6392) at /mariadb/10.3/storage/innobase/include/ib0mutex.h:590
 
#11 0x0000555cc9ac9a43 in lock_trx_handle_wait (trx=0x7f6d663b9288) at /mariadb/10.3/storage/innobase/lock/lock0lock.cc:6392
 
#12 0x0000555cc9a33906 in innobase_kill_query (thd=0x7f6ce4000cf8) at /mariadb/10.3/storage/innobase/handler/ha_innodb.cc:5129
 
#13 0x0000555cc982e816 in kill_handlerton (thd=0x7f6ce4000cf8, plugin=0x7f6cf8155608, level=0x7f6d65b530b4) at /mariadb/10.3/sql/handler.cc:813
 
#14 0x0000555cc9569ae7 in plugin_foreach_with_mask (thd=0x7f6ce4000cf8, func=0x555cc982e798 <kill_handlerton(THD*, plugin_ref, void*)>, type=1, state_mask=8, arg=0x7f6d65b530b4) at /mariadb/10.3/sql/sql_plugin.cc:2422
 
#15 0x0000555cc982e870 in ha_kill_query (thd=0x7f6ce4000cf8, level=THD_ABORT_SOFTLY) at /mariadb/10.3/sql/handler.cc:820
 
#16 0x0000555cc94eb5a0 in THD::awake_no_mutex (this=0x7f6ce4000cf8, state_to_set=KILL_QUERY) at /mariadb/10.3/sql/sql_class.cc:1829
 
#17 0x0000555cc9474152 in THD::awake (this=0x7f6ce4000cf8, state_to_set=KILL_QUERY) at /mariadb/10.3/sql/sql_class.h:3299
 
#18 0x0000555cc9754866 in wsrep_thd_awake (thd=0x7f6ce4000cf8, signal=1 '\001') at /mariadb/10.3/sql/wsrep_mysqld.cc:2516
 
#19 0x0000555cc9a4f376 in wsrep_innobase_kill_one_trx (bf_thd_ptr=0x7f6cf8000cf8, bf_trx=0x7f6d663b70e8, victim_trx=0x7f6d663b9288, signal=1) at /mariadb/10.3/storage/innobase/handler/ha_innodb.cc:18708
 
#20 0x0000555cc9a4f7d1 in wsrep_abort_transaction (bf_thd=0x7f6cf8000cf8, victim_thd=0x7f6ce4000cf8, signal=1 '\001') at /mariadb/10.3/storage/innobase/handler/ha_innodb.cc:18784
 
#21 0x0000555cc983cb14 in ha_abort_transaction (bf_thd=0x7f6cf8000cf8, victim_thd=0x7f6ce4000cf8, signal=1 '\001') at /mariadb/10.3/sql/handler.cc:6526
 
#22 0x0000555cc976233b in wsrep_abort_thd (bf_thd_ptr=0x7f6cf8000cf8, victim_thd_ptr=0x7f6ce4000cf8, signal=1 '\001') at /mariadb/10.3/sql/wsrep_thd.cc:655
 
#23 0x0000555cc9752f20 in wsrep_grant_mdl_exception (requestor_ctx=0x7f6cf8000e18, ticket=0x7f6ce411de60, key=0x7f6cf80cc158) at /mariadb/10.3/sql/wsrep_mysqld.cc:1903
 
#24 0x0000555cc96b1a74 in MDL_lock::can_grant_lock (this=0x7f6cf80cc158, type_arg=MDL_EXCLUSIVE, requestor_ctx=0x7f6cf8000e18, ignore_lock_priority=false) at /mariadb/10.3/sql/mdl.cc:1594
 
#25 0x0000555cc96b235e in MDL_context::try_acquire_lock_impl (this=0x7f6cf8000e18, mdl_request=0x7f6cf8022518, out_ticket=0x7f6d65b53578) at /mariadb/10.3/sql/mdl.cc:1925
 
#26 0x0000555cc96b26f6 in MDL_context::acquire_lock (this=0x7f6cf8000e18, mdl_request=0x7f6cf8022518, lock_wait_timeout=600) at /mariadb/10.3/sql/mdl.cc:2069
 
#27 0x0000555cc96b2fdf in MDL_context::acquire_locks (this=0x7f6cf8000e18, mdl_requests=0x7f6d65b536f0, lock_wait_timeout=600) at /mariadb/10.3/sql/mdl.cc:2268
 
#28 0x0000555cc94c61c7 in lock_table_names (thd=0x7f6cf8000cf8, options=..., tables_start=0x7f6cf80220c0, tables_end=0x0, lock_wait_timeout=600, flags=0) at /mariadb/10.3/sql/sql_base.cc:3827
 
#29 0x0000555cc94c6738 in open_tables (thd=0x7f6cf8000cf8, options=..., start=0x7f6d65b53a28, counter=0x7f6d65b53a44, flags=0, prelocking_strategy=0x7f6d65b53ac8) at /mariadb/10.3/sql/sql_base.cc:4045
 
#30 0x0000555cc94c8592 in open_and_lock_tables (thd=0x7f6cf8000cf8, options=..., tables=0x7f6cf80220c0, derived=false, flags=0, prelocking_strategy=0x7f6d65b53ac8) at /mariadb/10.3/sql/sql_base.cc:4953
 
#31 0x0000555cc95622da in open_and_lock_tables (thd=0x7f6cf8000cf8, options=..., tables=0x7f6cf80220c0, derived=false, flags=0) at /mariadb/10.3/sql/sql_base.h:488
 
#32 0x0000555cc961db5a in mysql_create_table (thd=0x7f6cf8000cf8, create_table=0x7f6cf80220c0, create_info=0x7f6d65b53e90, alter_info=0x7f6d65b53dd0) at /mariadb/10.3/sql/sql_table.cc:5157
 
#33 0x0000555cc954fba6 in mysql_execute_command (thd=0x7f6cf8000cf8) at /mariadb/10.3/sql/sql_parse.cc:4280
 
#34 0x0000555cc955c085 in mysql_parse (thd=0x7f6cf8000cf8, rawbuf=0x7f6cf8021f70 "CREATE TABLE t1 (f1 INTEGER AUTO_INCREMENT PRIMARY KEY, f2 INTEGER) Engine=InnoDB", length=81, parser_state=0x7f6d65b545a0, is_com_multi=false, is_next_command=false) at /mariadb/10.3/sql/sql_parse.cc:8089



 Comments   
Comment by Jan Lindström (Inactive) [ 2018-09-17 ]

Similar looking crash:

CURRENT_TEST: galera.GAL-382
 
mysqltest: At line 10: query 'create table t1 (i int, j int, k int, primary key pk(i)) engine=innodb' failed: 2013: Lost connection to MySQL server during query
 
#7  0x00007f95e241cb02 in __GI___assert_fail (assertion=0x56365f0f1f7e "!is_owned()", file=0x56365f0f1f48 "/mariadb/10.2/storage/innobase/include/sync0policy.ic", line=64, function=0x56365f0f2980 <MutexDebug<TTASEventMutex<GenericPolicy> >::enter(TTASEventMutex<GenericPolicy> const*, char const*, unsigned int)::__PRETTY_FUNCTION__> "void MutexDebug<Mutex>::enter(const Mutex*, const char*, unsigned int) [with Mutex = TTASEventMutex<GenericPolicy>]") at assert.c:101
 
#8  0x000056365ea08b52 in MutexDebug<TTASEventMutex<GenericPolicy> >::enter (this=0x563661c87ee0, mutex=0x563661c87ed0, name=0x56365f10acc8 "/mariadb/10.2/storage/innobase/lock/lock0lock.cc", line=6949) at /mariadb/10.2/storage/innobase/include/sync0policy.ic:64
 
#9  0x000056365ea07da6 in GenericPolicy<TTASEventMutex<GenericPolicy> >::enter (this=0x563661c87ee0, mutex=..., filename=0x56365f10acc8 "/mariadb/10.2/storage/innobase/lock/lock0lock.cc", line=6949) at /mariadb/10.2/storage/innobase/include/sync0policy.h:348
 
#10 0x000056365ea064aa in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (this=0x563661c87ed0, n_spins=30, n_delay=6, name=0x56365f10acc8 "/mariadb/10.2/storage/innobase/lock/lock0lock.cc", line=6949) at /mariadb/10.2/storage/innobase/include/ib0mutex.h:635
 
#11 0x000056365ea68abe in lock_trx_handle_wait (trx=0x7f95d8b08258) at /mariadb/10.2/storage/innobase/lock/lock0lock.cc:6949
 
#12 0x000056365e9dfb48 in innobase_kill_query (thd=0x7f955c000cf8) at /mariadb/10.2/storage/innobase/handler/ha_innodb.cc:5247
 
#13 0x000056365e7e08dc in kill_handlerton (thd=0x7f955c000cf8, plugin=0x7f956801f6a8, level=0x7f95cbffae24) at /mariadb/10.2/sql/handler.cc:808
 
#14 0x000056365e593b61 in plugin_foreach_with_mask (thd=0x7f955c000cf8, func=0x56365e7e085e <kill_handlerton(THD*, plugin_ref, void*)>, type=1, state_mask=8, arg=0x7f95cbffae24) at /mariadb/10.2/sql/sql_plugin.cc:2398
 
#15 0x000056365e7e0936 in ha_kill_query (thd=0x7f955c000cf8, level=THD_ABORT_SOFTLY) at /mariadb/10.2/sql/handler.cc:815
 
#16 0x000056365e530ae6 in THD::awake (this=0x7f955c000cf8, state_to_set=KILL_QUERY) at /mariadb/10.2/sql/sql_class.cc:1710
 
#17 0x000056365e749469 in wsrep_thd_awake (thd=0x7f955c000cf8, signal=1 '\001') at /mariadb/10.2/sql/wsrep_mysqld.cc:2527
 
#18 0x000056365e9fc545 in wsrep_innobase_kill_one_trx (bf_thd_ptr=0x7f9568000cf8, bf_trx=0x0, victim_trx=0x7f95d8b08258, signal=1) at /mariadb/10.2/storage/innobase/handler/ha_innodb.cc:19445
 
#19 0x000056365e9fcb88 in wsrep_abort_transaction (hton=0x563661b413c8, bf_thd=0x7f9568000cf8, victim_thd=0x7f955c000cf8, signal=1 '\001') at /mariadb/10.2/storage/innobase/handler/ha_innodb.cc:19521
 
#20 0x000056365e7ed295 in ha_abort_transaction (bf_thd=0x7f9568000cf8, victim_thd=0x7f955c000cf8, signal=1 '\001') at /mariadb/10.2/sql/handler.cc:6168
 
#21 0x000056365e75a208 in wsrep_abort_thd (bf_thd_ptr=0x7f9568000cf8, victim_thd_ptr=0x7f955c000cf8, signal=1 '\001') at /mariadb/10.2/sql/wsrep_thd.cc:656
 
#22 0x000056365e74750b in wsrep_grant_mdl_exception (requestor_ctx=0x7f9568000e18, ticket=0x7f955c128cb0, key=0x7f9560320c08) at /mariadb/10.2/sql/wsrep_mysqld.cc:1904
 
#23 0x000056365e6c8b59 in MDL_lock::can_grant_lock (this=0x7f9560320c08, type_arg=MDL_EXCLUSIVE, requestor_ctx=0x7f9568000e18, ignore_lock_priority=false) at /mariadb/10.2/sql/mdl.cc:1592
 
#24 0x000056365e6c945e in MDL_context::try_acquire_lock_impl (this=0x7f9568000e18, mdl_request=0x7f9568010d18, out_ticket=0x7f95cbffcae8) at /mariadb/10.2/sql/mdl.cc:1923
 
#25 0x000056365e6c97d2 in MDL_context::acquire_lock (this=0x7f9568000e18, mdl_request=0x7f9568010d18, lock_wait_timeout=0) at /mariadb/10.2/sql/mdl.cc:2067
 
#26 0x000056365e6c9fc3 in MDL_context::acquire_locks (this=0x7f9568000e18, mdl_requests=0x7f95cbffcc60, lock_wait_timeout=0) at /mariadb/10.2/sql/mdl.cc:2258
 
#27 0x000056365e50c58c in lock_table_names (thd=0x7f9568000cf8, options=..., tables_start=0x7f95680108d0, tables_end=0x0, lock_wait_timeout=0, flags=0) at /mariadb/10.2/sql/sql_base.cc:3722
 
#28 0x000056365e50cad0 in open_tables (thd=0x7f9568000cf8, options=..., start=0x7f95cbffcf98, counter=0x7f95cbffcfb4, flags=0, prelocking_strategy=0x7f95cbffd038) at /mariadb/10.2/sql/sql_base.cc:3940
 
#29 0x000056365e50e3af in open_and_lock_tables (thd=0x7f9568000cf8, options=..., tables=0x7f95680108d0, derived=false, flags=0, prelocking_strategy=0x7f95cbffd038) at /mariadb/10.2/sql/sql_base.cc:4727
 
#30 0x000056365e58c490 in open_and_lock_tables (thd=0x7f9568000cf8, options=..., tables=0x7f95680108d0, derived=false, flags=0) at /mariadb/10.2/sql/sql_base.h:492
 
#31 0x000056365e63fec6 in mysql_create_table (thd=0x7f9568000cf8, create_table=0x7f95680108d0, create_info=0x7f95cbffd430, alter_info=0x7f95cbffd380) at /mariadb/10.2/sql/sql_table.cc:5058
 
#32 0x000056365e579275 in mysql_execute_command (thd=0x7f9568000cf8) at /mariadb/10.2/sql/sql_parse.cc:3988
 
#33 0x000056365e585dc7 in mysql_parse (thd=0x7f9568000cf8, rawbuf=0x7f9568010798 "create table t1 (i int, j int, k int, primary key pk(i)) engine=innodb", length=70, parser_state=0x7f95cbffe1b0, is_com_multi=false, is_next_command=false) at /mariadb/10.2/sql/sql_parse.cc:8009

Comment by Seppo Jaakola [ 2018-10-01 ]

I cannot reproduce this issue with the above tests.
The stacktrace suggests that crash happens practically with the first SQL statement, which creates the test table. And this statement execution interferes with some other thread, which is not launched by the test script itself. So what else was happening with these nodes at the time of testing? Do you have error logs from node 1?

Comment by Jan Lindström (Inactive) [ 2018-11-15 ]

I could not reproduce this issue also, so marking it as a fixed.

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