[MDEV-30224] Assertion `(lock_sys.mutex.is_owned())' failed in dberr_t lock_trx_handle_wait_low(trx_t*) Created: 2022-12-14  Updated: 2023-04-11

Status: Stalled
Project: MariaDB Server
Component/s: Galera
Affects Version/s: 10.4
Fix Version/s: 10.4

Type: Bug Priority: Major
Reporter: Ramesh Sivaraman Assignee: Julius Goryavsky
Resolution: Unresolved Votes: 0
Labels: debug


 Description   

Multi master RQG full text search run crashes Galera secondary node.

perl runall-new.pl \
   --basedir=/test/GAL_MD071222-mariadb-10.4.28-linux-x86_64-dbg \
   --vardir=/home/ramesh/galera-rqg-test \
   --mysqld=--wsrep-provider=/test/GAL_MD071222-mariadb-10.4.28-linux-x86_64-dbg/lib/libgalera_smm.so \
   --gendata=conf/engines/innodb/full_text_search.zz \
   --grammar=conf/engines/innodb/full_text_search.yy \
   --threads=16 \
   --galera=mms \
   --mysqld=--wsrep_sst_method=rsync \
   --mysqld=--core \
   --mysqld=--general-log \
   --mysqld=--general-log-file=queries.log \
   --mysqld=--log-output=file \
   --mysqld=--wsrep-debug=0 \
   --mysqld=--wsrep_retry_autocommit=0 \
   --mysqld=--wsrep_slave_threads=12 \
   --mysqld=--wsrep_on=1 \
   --mysqld=--default-storage-engine=innodb \
   --mysqld=--sort_buffer_size=200M \
   --mysqld=--innodb-lock-wait-timeout=1 \
   --mysqld=--log_bin=binlog \
   --mysqld=--binlog_format=ROW \
   --mysqld=--master_info_repository=TABLE \
   --mysqld=--relay_log_info_repository=TABLE 

Leads to

10.4.28 07a06022c4e63adc360b42775934f35fa1df5a79 (Debug)

#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
56	../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
[Current thread is 1 (Thread 0x14665f2ff700 (LWP 118053))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x0000559e59faaa33 in my_write_core (sig=sig@entry=6) at /test/10.4_dbg/mysys/stacktrace.c:386
#2  0x0000559e597bef78 in handle_fatal_signal (sig=6) at /test/10.4_dbg/sql/signal_handler.cc:366
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#5  0x00001466cbeb7859 in __GI_abort () at abort.c:79
#6  0x00001466cbeb7729 in __assert_fail_base (fmt=0x1466cc04d588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x559e5a319fcc "(lock_sys.mutex.is_owned())", 
    file=0x559e5a31a450 "/test/10.4_dbg/storage/innobase/lock/lock0lock.cc", line=6299, function=<optimized out>) at assert.c:92
#7  0x00001466cbec8fd6 in __GI___assert_fail (assertion=assertion@entry=0x559e5a319fcc "(lock_sys.mutex.is_owned())", file=file@entry=0x559e5a31a450 "/test/10.4_dbg/storage/innobase/lock/lock0lock.cc", 
    line=line@entry=6299, function=function@entry=0x559e5a31c680 "dberr_t lock_trx_handle_wait_low(trx_t*)") at assert.c:101
#8  0x0000559e59b7213a in lock_trx_handle_wait_low (trx=0x1466c81e8ea0) at /test/10.4_dbg/storage/innobase/include/ib0mutex.h:639
#9  lock_trx_handle_wait (trx=trx@entry=0x1466c81e8ea0) at /test/10.4_dbg/storage/innobase/lock/lock0lock.cc:6327
#10 0x0000559e59cc840d in row_search_mvcc (buf=buf@entry=0x14660c97cd80 "", mode=PAGE_CUR_G, mode@entry=PAGE_CUR_UNSUPP, prebuilt=0x14660c981f60, match_mode=match_mode@entry=0, direction=direction@entry=1)
    at /test/10.4_dbg/storage/innobase/row/row0sel.cc:5191
#11 0x0000559e59adc4e3 in ha_innobase::general_fetch (this=0x14660c974930, buf=0x14660c97cd80 "", direction=direction@entry=1, match_mode=match_mode@entry=0)
    at /test/10.4_dbg/storage/innobase/handler/ha_innodb.cc:9674
#12 0x0000559e59ae5c40 in ha_innobase::rnd_next (this=0x14660c974930, buf=<optimized out>) at /test/10.4_dbg/storage/innobase/handler/ha_innodb.cc:9884
#13 0x0000559e597c4f45 in handler::ha_rnd_next (this=0x14660c974930, buf=0x14660c97cd80 "") at /test/10.4_dbg/sql/handler.cc:2891
#14 0x0000559e5996efeb in rr_sequential (info=0x14665f2fc6d0) at /test/10.4_dbg/sql/records.h:71
#15 0x0000559e59625659 in READ_RECORD::read_record (this=0x14665f2fc6d0) at /test/10.4_dbg/sql/records.h:70
#16 mysql_update (thd=thd@entry=0x1465f4000d28, table_list=<optimized out>, fields=..., values=..., conds=<optimized out>, order_num=<optimized out>, order=<optimized out>, limit=18446744073709551615, 
    ignore=<optimized out>, found_return=<optimized out>, updated_return=<optimized out>) at /test/10.4_dbg/sql/sql_update.cc:1001
#17 0x0000559e59549358 in mysql_execute_command (thd=thd@entry=0x1465f4000d28) at /test/10.4_dbg/sql/sql_parse.cc:4437
#18 0x0000559e59550d78 in mysql_parse (thd=thd@entry=0x1465f4000d28, 
    rawbuf=rawbuf@entry=0x1465f4012550 "UPDATE /* QNO 347 CON_ID 31 */ `table400_innodb_int_autoinc` SET `col_char_255_latin1_fulltext_key` = 'session' WHERE MATCH (`col_char_255_latin1_fulltext_key_default_null`) AGAINST ('fool' IN NATURAL"..., length=length@entry=216, parser_state=parser_state@entry=0x14665f2fe3b0, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false)
    at /test/10.4_dbg/sql/sql_parse.cc:7984
#19 0x0000559e59551bb1 in wsrep_mysql_parse (thd=thd@entry=0x1465f4000d28, 
    rawbuf=0x1465f4012550 "UPDATE /* QNO 347 CON_ID 31 */ `table400_innodb_int_autoinc` SET `col_char_255_latin1_fulltext_key` = 'session' WHERE MATCH (`col_char_255_latin1_fulltext_key_default_null`) AGAINST ('fool' IN NATURAL"..., length=216, parser_state=parser_state@entry=0x14665f2fe3b0, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_parse.cc:7786
#20 0x0000559e5955378e in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1465f4000d28, 
    packet=packet@entry=0x1465f400a249 "UPDATE /* QNO 347 CON_ID 31 */ `table400_innodb_int_autoinc` SET `col_char_255_latin1_fulltext_key` = 'session' WHERE MATCH (`col_char_255_latin1_fulltext_key_default_null`) AGAINST ('fool' IN NATURAL"..., packet_length=packet_length@entry=216, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_class.h:1208
#21 0x0000559e59555f86 in do_command (thd=0x1465f4000d28) at /test/10.4_dbg/sql/sql_parse.cc:1378
#22 0x0000559e5967209a in do_handle_one_connection (connect=<optimized out>) at /test/10.4_dbg/sql/sql_connect.cc:1419
#23 0x0000559e59672156 in handle_one_connection (arg=<optimized out>) at /test/10.4_dbg/sql/sql_connect.cc:1323
#24 0x00001466cc3c8609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#25 0x00001466cbfb4133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95



 Comments   
Comment by Jan Lindström [ 2023-04-11 ]

sysprg Please analyze rr-trace and provide more detailed information for us if needed. I can't access galapq.

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