Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.3.14
-
None
Description
Server crashes while executing ANALYZE FORMAT=JSON for complex enough query having WITH RECURSIVE clause. Stack trace is:
Server version: 10.3.14-MariaDB-log
|
key_buffer_size=33554432
|
read_buffer_size=2097152
|
max_used_connections=18
|
max_threads=5010
|
thread_count=15
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 30832274 K bytes of memory
|
Hope that's ok; if not, decrease some variables in the equation.
|
|
|
Thread pointer: 0x7f56400e1ae8
|
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 = 0x7f56e34e2dd8 thread_stack 0x49000
|
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x2b)[0x55b150cfa30b]
|
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x537)[0x55b1507e7f47]
|
/lib64/libpthread.so.0(+0xf5d0)[0x7f59792875d0]
|
/usr/local/mysql/bin/mysqld(_ZN10Item_field5printEP6String15enum_query_type+0x14)[0x55b1507ffd24]
|
/usr/local/mysql/bin/mysqld(_ZN19Item_func_isnotnull5printEP6String15enum_query_type+0x3d)[0x55b15081496d]
|
sql/item.cc:7715(Item_field::print(String*, enum_query_type))[0x55b150714166]
|
sql/item_cmpfunc.cc:5200(Item_func_isnotnull::print(String*, enum_query_type))[0x55b150717b36]
|
sql/sql_string.h:218(String::c_ptr_safe())[0x55b15071862f]
|
sql/sql_explain.cc:1550(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x55b150718ae7]
|
sql/sql_explain.cc:1058(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x55b150715336]
|
sql/sql_explain.cc:955(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x55b150717f21]
|
sql/sql_explain.cc:1753(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x55b15071862f]
|
sql/sql_explain.cc:1058(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x55b1507189d7]
|
sql/sql_explain.cc:955(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x55b150717f21]
|
sql/sql_explain.cc:1753(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x55b15071862f]
|
sql/sql_explain.cc:1058(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x55b150718ae7]
|
sql/sql_explain.cc:955(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x55b150714a0c]
|
sql/sql_explain.cc:229(Explain_query::print_explain_json(select_result_sink*, bool))[0x55b150714af0]
|
sql/sql_explain.cc:179(Explain_query::send_explain(THD*))[0x55b1505447e1]
|
sql/sql_parse.cc:6560(execute_sqlcom_select(THD*, TABLE_LIST*))[0x55b15062da69]
|
sql/sql_parse.cc:3821(mysql_execute_command(THD*))[0x55b15062fd19]
|
sql/sql_class.h:1820(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x55b150631e95]
|
sql/sql_parse.cc:1857(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x55b15063263e]
|
sql/sql_parse.cc:1405(do_command(THD*))[0x55b1507331b7]
|
sql/threadpool_common.cc:358(threadpool_process_request)[0x55b1507be2c8]
|
sql/threadpool_generic.cc:1601(worker_main(void*))[0x55b15095f35d]
|
/lib64/libpthread.so.0(+0x7dd5)[0x7f597927fdd5]
|
/lib64/libc.so.6(clone+0x6d)[0x7f597815aead]
|
It looks very similar to the one in MDEV-8864 fixed long time ago.
Attachments
Issue Links
- relates to
-
-
- Closed
-
Activity
With the test case from MDEV-22121 on 10.3.14 non-debug build with ASAN I am getting this:
|
10.3.14 |
==18302==ERROR: AddressSanitizer: heap-use-after-free on address 0x6190000e15c0 at pc 0x561ac0780ea9 bp 0x7fd0745f1850 sp 0x7fd0745f1848
|
READ of size 8 at 0x6190000e15c0 thread T27
|
#0 0x561ac0780ea8 in Item_field::print(String*, enum_query_type) /data/src/10.3-bug/sql/item.cc:7715
|
#1 0x561ac07d427b in Item_func_isnotnull::print(String*, enum_query_type) /data/src/10.3-bug/sql/item_cmpfunc.cc:5199
|
#2 0x561ac04989ee in write_item /data/src/10.3-bug/sql/sql_explain.cc:1407
|
#3 0x561ac04a98b4 in Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:1712
|
#4 0x561ac04aaaf8 in Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:1056
|
#5 0x561ac04ab132 in Explain_select::print_explain_json(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:955
|
#6 0x561ac049e9c6 in Explain_union::print_explain_json(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:611
|
#7 0x561ac04aa003 in Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:1752
|
#8 0x561ac04aaaf8 in Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:1056
|
#9 0x561ac04ab264 in Explain_basic_join::print_explain_json(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:1039
|
#10 0x561ac04a9bc7 in Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:1770
|
#11 0x561ac04aaaf8 in Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:1056
|
#12 0x561ac04ab132 in Explain_select::print_explain_json(Explain_query*, Json_writer*, bool) /data/src/10.3-bug/sql/sql_explain.cc:955
|
#13 0x561ac049beb1 in Explain_query::print_explain_json(select_result_sink*, bool) /data/src/10.3-bug/sql/sql_explain.cc:229
|
#14 0x561ac049c209 in Explain_query::send_explain(THD*) /data/src/10.3-bug/sql/sql_explain.cc:172
|
#15 0x561ac012a157 in execute_sqlcom_select /data/src/10.3-bug/sql/sql_parse.cc:6560
|
#16 0x561ac0141e9a in mysql_execute_command(THD*) /data/src/10.3-bug/sql/sql_parse.cc:3821
|
#17 0x561ac015cc89 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3-bug/sql/sql_parse.cc:8091
|
#18 0x561ac0163b9c in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3-bug/sql/sql_parse.cc:1856
|
#19 0x561ac016652f in do_command(THD*) /data/src/10.3-bug/sql/sql_parse.cc:1402
|
#20 0x561ac04447fd in do_handle_one_connection(CONNECT*) /data/src/10.3-bug/sql/sql_connect.cc:1402
|
#21 0x561ac0444e4a in handle_one_connection /data/src/10.3-bug/sql/sql_connect.cc:1308
|
#22 0x561ac15e8206 in pfs_spawn_thread /data/src/10.3-bug/storage/perfschema/pfs.cc:1862
|
#23 0x7fd08aabffa2 in start_thread /build/glibc-vjB4T1/glibc-2.28/nptl/pthread_create.c:486
|
#24 0x7fd08a30e4ce in clone (/lib/x86_64-linux-gnu/libc.so.6+0xf94ce)
|
|
|
0x6190000e15c0 is located 64 bytes inside of 992-byte region [0x6190000e1580,0x6190000e1960)
|
freed by thread T27 here:
|
#0 0x7fd08abc1fb0 in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0xe8fb0)
|
#1 0x561ac169641b in free_root /data/src/10.3-bug/mysys/my_alloc.c:428
|
|
|
previously allocated by thread T27 here:
|
#0 0x7fd08abc2330 in __interceptor_malloc (/lib/x86_64-linux-gnu/libasan.so.5+0xe9330)
|
#1 0x561ac16a95dc in my_malloc /data/src/10.3-bug/mysys/my_malloc.c:101
|
|
|
Thread T27 created by T0 here:
|
#0 0x7fd08ab29db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
|
#1 0x561ac15ef832 in spawn_thread_v1 /data/src/10.3-bug/storage/perfschema/pfs.cc:1912
|
|
|
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.3-bug/sql/item.cc:7715 in Item_field::print(String*, enum_query_type)
|
Shadow bytes around the buggy address:
|
0x0c3280014260: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
|
0x0c3280014270: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
|
0x0c3280014280: fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa fa
|
0x0c3280014290: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c32800142a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
=>0x0c32800142b0: fd fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd fd
|
0x0c32800142c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
|
0x0c32800142d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
|
0x0c32800142e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
|
0x0c32800142f0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
|
0x0c3280014300: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
|
Shadow byte legend (one shadow byte represents 8 application bytes):
|
Addressable: 00
|
Partially addressable: 01 02 03 04 05 06 07
|
Heap left redzone: fa
|
Freed heap region: fd
|
Stack left redzone: f1
|
Stack mid redzone: f2
|
Stack right redzone: f3
|
Stack after return: f5
|
Stack use after scope: f8
|
Global redzone: f9
|
Global init order: f6
|
Poisoned by user: f7
|
Container overflow: fc
|
Array cookie: ac
|
Intra object redzone: bb
|
ASan internal: fe
|
Left alloca redzone: ca
|
Right alloca redzone: cb
|
==18302==ABORTING
|
I would say it is as close to the description as it ever gets, given that SIGSEGV on an optimized build is a matter of luck and non-perfect stack trace.
Changed the population of the table t2 in the first test case of MDEV-22121 to stabilize the chosen execution plan:
insert into t2 values (1,1),(2,2),(3,3),(4,4); |
Compiled with Valgrind
cmake . -DCMAKE_BUILD_TYPE=Debug -DWITHOUT_MROONGA:bool=1 -DWITHOUT_TOKUDB:bool=1 -DWITH_VALGRIND:BOOL=1
|
The test of MDEV-22121 passes. Yet Valgrind resports the following problem
==32444== Invalid read of size 8
|
==32444== at 0xB7E9F8: Item_field::print(String*, enum_query_type) (item.cc:7769)
|
==32444== by 0xB67838: Item::print_parenthesised(String*, enum_query_type, precedence) (item.cc:611)
|
==32444== by 0xBA3372: Item_func_isnotnull::print(String*, enum_query_type) (item_cmpfunc.cc:5214)
|
==32444== by 0x9E1457: write_item(Json_writer*, Item*) (sql_explain.cc:1414)
|
==32444== by 0x9E1739: Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag) (sql_explain.cc:1472)
|
==32444== by 0x9E2353: Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) (sql_explain.cc:1719)
|
==32444== by 0x9E0078: Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) (sql_explain.cc:1063)
|
==32444== by 0x9DFAEB: Explain_select::print_explain_json(Explain_query*, Json_writer*, bool) (sql_explain.cc:962)
|
==32444== by 0x9DE9C5: Explain_union::print_explain_json(Explain_query*, Json_writer*, bool) (sql_explain.cc:613)
|
==32444== by 0x9E2687: Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) (sql_explain.cc:1764)
|
==32444== by 0x9E0078: Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) (sql_explain.cc:1063)
|
==32444== by 0x9DFFC8: Explain_basic_join::print_explain_json(Explain_query*, Json_writer*, bool) (sql_explain.cc:1046)
|
==32444== by 0x9E27F4: Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) (sql_explain.cc:1782)
|
==32444== by 0x9E0078: Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) (sql_explain.cc:1063)
|
==32444== by 0x9DFAEB: Explain_select::print_explain_json(Explain_query*, Json_writer*, bool) (sql_explain.cc:962)
|
==32444== by 0x9DCFA7: Explain_query::print_explain_json(select_result_sink*, bool) (sql_explain.cc:229)
|
==32444== Address 0x19a4d630 is 64 bytes inside a block of size 264 free'd
|
==32444== at 0x4C2A37C: free (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so)
|
==32444== by 0x13B973E: my_free (my_malloc.c:223)
|
==32444== by 0x13AC0DC: free_root (my_alloc.c:420)
|
==32444== by 0x8A0E5B: free_tmp_table(THD*, TABLE*) (sql_select.cc:19017)
|
==32444== by 0x78C5FD: close_thread_tables(THD*) (sql_base.cc:798)
|
==32444== by 0x747294: sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) (sp_head.cc:3359)
|
==32444== by 0x747DB8: sp_instr_set::execute(THD*, unsigned int*) (sp_head.cc:3626)
|
==32444== by 0x74150D: sp_head::execute(THD*, bool) (sp_head.cc:1371)
|
==32444== by 0x743109: sp_head::execute_function(THD*, Item**, unsigned int, Field*, sp_rcontext**, Query_arena*) (sp_head.cc:2029)
|
==32444== by 0xB6F868: Item_sp::execute_impl(THD*, Item**, unsigned int) (item.cc:3020)
|
==32444== by 0xB6F42A: Item_sp::execute(THD*, bool*, Item**, unsigned int) (item.cc:2933)
|
==32444== by 0xBEA5AB: Item_func_sp::execute() (item_func.cc:6410)
|
==32444== by 0xBF0E13: Item_func_sp::val_str(String*) (item_func.h:2959)
|
==32444== by 0xA342DA: Type_handler::Item_send_str(Item*, Protocol*, st_value*) const (sql_type.cc:5380)
|
==32444== by 0xA39339: Type_handler_string_result::Item_send(Item*, Protocol*, st_value*) const (sql_type.h:2250)
|
==32444== by 0x714B97: Item::send(Protocol*, st_value*) (item.h:880)
|
As we can see the problem appears exactly with the same stack as in the reported crash.
I failed to reproduce the issue, as I am getting
MDEV-22121(or sometimesMDEV-16230because of the window function). It might be a variation of the same problem or it should be investigated further after the fixMDEV-22121.