[MDEV-23750] MariaDB 10.4.12 crashed Created: 2020-09-18  Updated: 2021-02-11  Resolved: 2020-10-20

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.4.12
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Kuijun Cui Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: need_feedback
Environment:

CentOS Linux release 7.7.1908 (Core)
3.10.0-1062.12.1.el7.x86_64


Issue Links:
Relates
relates to MDEV-20727 Crash in memcpy call by my_b_write, a... Closed

 Description   

Database Alert:

Server version: 10.4.12-MariaDB-log
key_buffer_size=10485760
read_buffer_size=131072
max_used_connections=43
max_threads=30001
thread_count=30
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 126759176 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
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 = 0x0 thread_stack 0x49000
/opt/maria10.1/bin/mysqld(my_print_stacktrace+0x29)[0x55958cd9bad9]
/opt/maria10.1/bin/mysqld(handle_fatal_signal+0x30f)[0x55958c8c960f]
/lib64/libpthread.so.0(+0xf5f0)[0x7f3c2df155f0]
/opt/maria10.1/bin/mysqld(+0xd2532b)[0x55958cd5f32b]
/opt/maria10.1/bin/mysqld(+0x9fa942)[0x55958ca34942]
/opt/maria10.1/bin/mysqld(_Z9get_eventP15worker_thread_tP14thread_group_tP8timespec+0x265)[0x55958ca35cf5]
/opt/maria10.1/bin/mysqld(+0x9fc039)[0x55958ca36039]
/opt/maria10.1/bin/mysqld(+0xd24074)[0x55958cd5e074]
/lib64/libpthread.so.0(+0x7e65)[0x7f3c2df0de65]

OS alert:

kernel: [16387501.680494] mysqld[14941]: segfault at 8 ip 0000564d0f98995b sp 00007fc9d578a610 error 4 in mysqld[564d0ef6b000+13db000]

---------------------------------------------------------------------------------------
Add extra stack information using addr2line command line tools:
mysql$ addr2line -f -p -i -e mysqld 0xd2532b
start_mutex_wait_v1 at /mariadb-10.4.12/storage/perfschema/pfs.cc:2222
mysql$ addr2line -f -p -i -e mysqld 0x9fa942
inline_mysql_mutex_lock at /mariadb-10.4.12/include/mysql/psi/mysql_thread.h:704
mysql$ addr2line -f -p -i -e mysqld 0x9fc039
_ZL11worker_mainPv at mariadb-10.4.12/sql/threadpool_generic.cc:1589
mysql$ addr2line -f -p -i -e mysqld 0xd24074
pfs_spawn_thread at /mariadb-10.4.12/storage/perfschema/pfs.cc:1872
mysql$ addr2line -f -i -e /lib64/libpthread.so.0 0x7e65
start_thread
pthread_create.c:?

This crash can not be reproduced, and no SQL can be offered.

--------------------------------------------------------------------------------------------------------
Hi, Marko, sorry for that can not do reproduce, after using offical debug version binary file, produce the below gdb debug info:

Program received signal SIGSEGV, Segmentation fault.
 
do_lookup_x (new_hash=new_hash@entry=969867160, old_hash=old_hash@entry=0x7f5160e675f0, result=result@entry=0x7f5160e67600, scope=<optimized out>, i=i@entry=0, flags=flags@entry=2, skip=skip@entry=0x0, undef_map=undef_map@entry=0x7f51807b44c8) at dl-lookup.c:98
 
98          const struct link_map *map = list[i]->l_real;
 
(gdb) bt
 
#0  do_lookup_x (new_hash=new_hash@entry=969867160, old_hash=old_hash@entry=0x7f5160e675f0, result=result@entry=0x7f5160e67600, scope=<optimized out>, i=i@entry=0, flags=flags@entry=2, skip=skip@entry=0x0, undef_map=undef_map@entry=0x7f51807b44c8)
 
    at dl-lookup.c:98
 
#1  0x00007f51805ac08f in _dl_lookup_symbol_x (undef_name=0x7f517e7ba0a4 "_Unwind_Backtrace", undef_map=0x7f51807b44c8, ref=0x7f5160e67838, symbol_scope=0x7f51807b4850, version=0x0, type_class=0, flags=2, skip_map=0x0) at dl-lookup.c:739
 
#2  0x00007f517e76d775 in do_dlsym (ptr=ptr@entry=0x7f5160e67820) at dl-libc.c:97
 
#3  0x00007f51805b17c4 in _dl_catch_error (objname=0x7f5160e67800, errstring=0x7f5160e67810, mallocedp=0x7f5160e677f0, operate=0x7f517e76d730 <do_dlsym>, args=0x7f5160e67820) at dl-error.c:177
 
#4  0x00007f517e76d879 in dlerror_run (args=0x7f5160e67820, operate=0x7f517e76d730 <do_dlsym>) at dl-libc.c:46
 
#5  __GI___libc_dlsym (map=<optimized out>, name=name@entry=0x7f517e7ba0a4 "_Unwind_Backtrace") at dl-libc.c:210
 
#6  0x00007f517e7449f0 in init () at ../sysdeps/x86_64/backtrace.c:57
 
#7  0x00007f518038c20b in __pthread_once_slow (once_control=0x7f517e9fbcc0 <once.7829>, init_routine=0x7f517e7449c0 <init>) at pthread_once.c:117
 
#8  0x00007f517e744aec in __GI___backtrace (array=array@entry=0x7f5160e67910, size=size@entry=128) at ../sysdeps/x86_64/backtrace.c:101
 
#9  0x000055cb4673fa1e in my_print_stacktrace (stack_bottom=0xbfcc600000001 <Address 0xbfcc600000001 out of bounds>, thread_stack=299008, silent=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/mysys/stacktrace.c:269
 
#10 0x000055cb461d3d8f in handle_fatal_signal (sig=11) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/signal_handler.cc:207
 
#11 <signal handler called>
 
#12 __memcpy_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:1633
 
#13 0x000055cb46720be1 in memcpy (__len=18446744073709551612, __src=0x7f51283457b8, __dest=<optimized out>) at /usr/include/bits/string3.h:51
 
#14 _my_b_write (info=0x7f5128101fd0, Buffer=0x7f51283457b8 "\242\261", Count=4) at /usr/src/debug/MariaDB-10.4.12/src_0/mysys/mf_iocache.c:596
 
#15 0x000055cb461d126a in my_b_write (Count=4, Buffer=<optimized out>, info=0x7f5128101fd0) at /usr/src/debug/MariaDB-10.4.12/src_0/include/my_sys.h:543
 
#16 merge_buffers (param=param@entry=0x7f5160e68580, from_file=from_file@entry=0x7f5128101bf8, to_file=to_file@entry=0x7f5128101fd0, sort_buffer=sort_buffer@entry=0x7f51282457b8 <incomplete sequence \327>, lastbuff=lastbuff@entry=0x7f51282451a8,
 
    Fb=Fb@entry=0x7f51282451a8, Tb=0x7f5128245208, flag=flag@entry=1) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/filesort.cc:1728
 
#17 0x000055cb461d1a6c in merge_index (param=param@entry=0x7f5160e68580, sort_buffer=sort_buffer@entry=0x7f51282457b8 <incomplete sequence \327>, buffpek=buffpek@entry=0x7f51282451a8, maxbuffer=<optimized out>, tempfile=tempfile@entry=0x7f5128101bf8,
 
    outfile=outfile@entry=0x7f5128101fd0) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/filesort.cc:1856
 
#18 0x000055cb4608efa7 in Unique::merge (this=this@entry=0x7f5128101bc8, table=table@entry=0x7f51280931e8, buff=buff@entry=0x7f51282457b8 <incomplete sequence \327>, without_last_merge=without_last_merge@entry=false)
 
    at /usr/src/debug/MariaDB-10.4.12/src_0/sql/uniques.cc:739
 
#19 0x000055cb4608f619 in Unique::get (this=this@entry=0x7f5128101bc8, table=table@entry=0x7f51280931e8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/uniques.cc:794
 
#20 0x000055cb462fceff in read_keys_and_merge_scans (thd=0x7f5128000ac8, head=0x7f51280931e8, quick_selects=..., pk_quick_select=0x0, read_record=0x7f5128106be8, intersection=intersection@entry=true, filtered_scans=0x7f5128106c80, unique_ptr=0x7f5128106b70)
 
    at /usr/src/debug/MariaDB-10.4.12/src_0/sql/opt_range.cc:11759
 
#21 0x000055cb462fd10b in QUICK_INDEX_INTERSECT_SELECT::read_keys_and_merge (this=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/opt_range.cc:11830
 
#22 0x000055cb460090fc in join_init_read_record (tab=0x7f51280fc8e8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:21263
 
#23 0x000055cb45ffa399 in sub_select (join=0x7f5128041d40, join_tab=0x7f51280fc8e8, end_of_records=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:20335
 
#24 0x000055cb4601c7fc in JOIN::exec_inner (this=this@entry=0x7f5128041d40) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:19876
 
#25 0x000055cb4601ca53 in JOIN::exec (this=0x7f5128041d40) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:4234
 
#26 0x000055cb462850f5 in subselect_single_select_engine::exec (this=0x7f512802f818) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item_subselect.cc:3935
 
#27 0x000055cb46283aba in Item_subselect::exec (this=0x7f512802f5f8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item_subselect.cc:746
 
#28 0x000055cb462845f4 in Item_in_subselect::val_bool (this=0x7f512802f5f8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item_subselect.cc:1804
 
#29 0x000055cb46214b1d in Item_in_optimizer::val_int (this=0x7f51280deee0) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item_cmpfunc.cc:1643
 
#30 0x000055cb461e815a in Item_cache_int::cache_value (this=0x7f51280fe320) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item.cc:9783
 
#31 0x000055cb461fe007 in cache (this=0x7f51280fe260) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item.cc:8564
 
#32 Item_cache_wrapper::val_bool (this=0x7f51280fe260) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item.cc:8750
 
#33 0x000055cb4620b15a in Item_cond_or::val_int (this=0x7f51280ec588) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item_cmpfunc.cc:5315
 
#34 0x000055cb460fb210 in Type_handler_int_result::Item_val_bool (this=<optimized out>, item=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_type.cc:4416
 
#35 0x000055cb4620b0da in Item_cond_and::val_int (this=0x7f51280ec470) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/item_cmpfunc.cc:5297
 
#36 0x000055cb45fed34d in evaluate_join_record (join=0x7f5128040eb8, join_tab=0x7f51280ea6b8, error=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:20433
 
#37 0x000055cb45ffa40c in sub_select (join=0x7f5128040eb8, join_tab=0x7f51280ea6b8, end_of_records=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:20377
 
#38 0x000055cb45fed5ac in evaluate_join_record (join=0x7f5128040eb8, join_tab=0x7f51280ea310, error=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:20558
 
#39 0x000055cb45ffa3ae in sub_select (join=0x7f5128040eb8, join_tab=0x7f51280ea310, end_of_records=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:20338
 
#40 0x000055cb4601c7fc in JOIN::exec_inner (this=this@entry=0x7f5128040eb8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:19876
 
#41 0x000055cb4601ca53 in JOIN::exec (this=0x7f5128040eb8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:4234
 
#42 0x000055cb4601ad56 in mysql_select (thd=thd@entry=0x7f5128000ac8, tables=0x7f512800d4c8, wild_num=0, fields=..., conds=0x7f51280e1868, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=proc_param@entry=0x0, select_options=2416184065,
 
    result=result@entry=0x7f5128040dd0, unit=unit@entry=0x7f512803ee80, select_lex=select_lex@entry=0x7f512800cea0) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:4666
 
#43 0x000055cb45f83857 in mysql_derived_fill (thd=<optimized out>, lex=0x7f5128004770, derived=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_derived.cc:1268
 
#44 0x000055cb45f833f4 in mysql_handle_single_derived (lex=0x7f5128004770, derived=0x7f512803f7b0, phases=96) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_derived.cc:206
 
#45 0x000055cb45ffa129 in st_join_table::preread_init (this=0x7f5128100770) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:13494
 
#46 0x000055cb45ffa368 in sub_select (join=0x7f5128040860, join_tab=0x7f5128100770, end_of_records=<optimized out>) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:20304
 
#47 0x000055cb4601c7fc in JOIN::exec_inner (this=this@entry=0x7f5128040860) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:19876
 
#48 0x000055cb4601ca53 in JOIN::exec (this=0x7f5128040860) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:4234
 
#49 0x000055cb4601ad56 in mysql_select (thd=0x7f5128000ac8, tables=0x7f512803f7b0, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7f5128040838, unit=0x7f5128004830,
 
    select_lex=0x7f512800c778) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:4666
 
#50 0x000055cb4601b8c7 in handle_select (thd=thd@entry=0x7f5128000ac8, lex=lex@entry=0x7f5128004770, result=result@entry=0x7f5128040838, setup_tables_done_option=setup_tables_done_option@entry=0) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_select.cc:420
 
#51 0x000055cb45eb53d4 in execute_sqlcom_select (thd=thd@entry=0x7f5128000ac8, all_tables=0x7f512803f7b0) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_parse.cc:6360
 
#52 0x000055cb45fc14fd in mysql_execute_command (thd=thd@entry=0x7f5128000ac8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_parse.cc:3899
 
#53 0x000055cb45fc64eb in mysql_parse (thd=thd@entry=0x7f5128000ac8, rawbuf=<optimized out>, length=6497, parser_state=parser_state@entry=0x7f5160e6bf20, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false)
 
    at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_parse.cc:7901
 
#54 0x000055cb45fc92ed in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f5128000ac8, packet=packet@entry=0x7f51280186e9 "\177", packet_length=packet_length@entry=6497, is_com_multi=is_com_multi@entry=false,
 
    is_next_command=is_next_command@entry=false) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_parse.cc:1842
 
#55 0x000055cb45fcaa4c in do_command (thd=0x7f5128000ac8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_parse.cc:1360
 
#56 0x000055cb460a9351 in do_handle_one_connection (connect=connect@entry=0x55cb4afb61c8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_connect.cc:1412
 
#57 0x000055cb460a940d in handle_one_connection (arg=arg@entry=0x55cb4afb61c8) at /usr/src/debug/MariaDB-10.4.12/src_0/sql/sql_connect.cc:1316
 
#58 0x000055cb466f1afd in pfs_spawn_thread (arg=0x55cb4afb9d18) at /usr/src/debug/MariaDB-10.4.12/src_0/storage/perfschema/pfs.cc:1869
 
#59 0x00007f518038dea5 in start_thread (arg=0x7f5160e6d700) at pthread_create.c:307
 
#60 0x00007f517e72e8dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

After many times try, the stack#0, seems match the below message from /var/log/message:

kernel: traps: mysqld[5246] general protection ip:7effb670c735 sp:7eff948094b0 error:0 in ld-2.17.so[7effb6703000+22000]

I don't know the above message whether can help to trace the issue, thank you for the follow up.

 Comments   
Comment by Marko Mäkelä [ 2020-09-18 ]

I think that we need more information in order to analyze the crash.

The provided stack trace does not include resolved addresses for some functions, and furthermore, it is showing a single thread only. The reason for the crash could be in another thread. Please try to follow the instructions in https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ and submit a resolved stack trace of all threads.

I think that we may also need the current SQL statement and the table definition SHOW CREATE TABLE, or the steps to reproduce the bug.

I wonder if this could in any way be related to the rowid_filter (MDEV-16188), which was the source of many regressions in MariaDB 10.4. The latest fix related to it that I remember is MDEV-21794 (10.4.13).

Comment by Marko Mäkelä [ 2020-09-21 ]

mrduin, line 2222 should not be invoking anything in libpthread.so:

  if (! pfs_mutex->m_enabled)

It seems to me that the current thread is executing (or waiting for something) inside libpthread.so, and the return address may be misleading. In release builds of 10.4.12, line 2222 should be the first one for which any code should be emitted.

Can you please disassemble that function in your executable so that we will have a better idea what was going on? In GDB, the command would be as follows:

disassemble start_mutex_wait_v1

If the execution is blocked inside libpthread.so, this might be a kernel bug, or something is sending the signal to the process.

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