[MDEV-23902] MariaDB crash on calling function Created: 2020-10-07  Updated: 2023-11-24  Resolved: 2023-09-19

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Procedure, Views
Affects Version/s: 10.3.24, 10.4.14, 10.5.5, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8
Fix Version/s: 10.4.32, 10.5.23, 10.6.16, 10.10.7, 10.11.6, 11.0.4, 11.1.3

Type: Bug Priority: Critical
Reporter: suresh ramagiri Assignee: Dmitry Shulga
Resolution: Fixed Votes: 1
Labels: None

Attachments: File maria.err     Text File mysqld_bt_all_threads.txt    
Issue Links:
Relates
relates to MDEV-26115 Crash when calling stored function in... Confirmed
relates to MDEV-32850 MariaDB got crash when call procedure Closed

 Description   

One of our customer observed server crashes, when calling a function, which invokes two other functions, involving some tables and a view.

This behavior is observed at the 10.3.24, 10.4.14 and 10.5.5 (the latest releases). Also, important to note customer has provided the related functions, tables, views details, through which I can locally able to reproduce the issue at our latest releases.

Attached is the dump.sql having all related functions, tables, views. Also, attaching full error log(maria.err), all threads backtrace(mysqld_bt_all_threads.txt) output.

To reproduce:

* Install 10.3.24 or 10.4.14 or 10.5.5(latest release) 
* restore the data - dump.sql
 
* At server.cnf put
 
lower_case_table_names=1
 
log-error=mariadb.err
 
core-file
 
* Start the server
 
* execute below SQL
 
select  FN_SPM_CHK_BCD_PUBL_TEST('1', '20200910') as aaa

Error log output:

201007  8:56:58 [ERROR] mysqld got signal 11 ;
 
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.24-MariaDB-log
 
key_buffer_size=268435456
 
read_buffer_size=8388608
 
max_used_connections=1
 
max_threads=1002
 
thread_count=9
 
It is possible that mysqld could use up to
 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 16701465 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x55af048a4038
 
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 = 0x7f854c7b5d30 thread_stack 0x49000
 
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55af0134351e]
 
/usr/sbin/mysqld(handle_fatal_signal+0x30f)[0x55af00dd8a4f]
 
sigaction.c:0(__restore_rt)[0x7f8562e16630]
 
/usr/sbin/mysqld(_ZN7Item_sp7cleanupEv+0x1b)[0x55af00df644b]
 
/usr/sbin/mysqld(_ZN12Item_func_sp7cleanupEv+0x18)[0x55af00e426f8]
 
/usr/sbin/mysqld(_Z13cleanup_itemsP4Item+0x21)[0x55af00bec581]
 
/usr/sbin/mysqld(_ZN7sp_head7executeEP3THDb+0x8d0)[0x55af00b65f40]
 
/usr/sbin/mysqld(_ZN7sp_head16execute_functionEP3THDPP4ItemjP5FieldPP11sp_rcontextP11Query_arena+0x582)[0x55af00b67ac2]
 
/usr/sbin/mysqld(_ZN7Item_sp12execute_implEP3THDPP4Itemj+0x128)[0x55af00df6618]
 
/usr/sbin/mysqld(_ZN7Item_sp7executeEP3THDPbPP4Itemj+0x21)[0x55af00df6861]
 
/usr/sbin/mysqld(_ZN12Item_func_sp7val_intEv+0x11)[0x55af00e5a271]
 
/usr/sbin/mysqld(_ZNK12Type_handler14Item_send_tinyEP4ItemP8ProtocolP8st_value+0x19)[0x55af00d2db19]
 
/usr/sbin/mysqld(_ZN8Protocol19send_result_set_rowEP4ListI4ItemE+0x13f)[0x55af00b4826f]
 
/usr/sbin/mysqld(_ZN11select_send9send_dataER4ListI4ItemE+0x53)[0x55af00bb4073]
 
/usr/sbin/mysqld(_ZN4JOIN10exec_innerEv+0xa5c)[0x55af00c51b1c]
 
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x33)[0x55af00c51d63]
 
/usr/sbin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x11a)[0x55af00c5026a]
 
/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1cc)[0x55af00c50d7c]
 
/usr/sbin/mysqld(+0x4daf06)[0x55af00b00f06]
 
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x63ba)[0x55af00bf98ca]
 
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x36d)[0x55af00bfc63d]
 
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0xfe1)[0x55af00bfded1]
 
/usr/sbin/mysqld(_Z10do_commandP3THD+0x11b)[0x55af00c0016b]
 
/usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x1d6)[0x55af00cd6a86]
 
/usr/sbin/mysqld(handle_one_connection+0x3d)[0x55af00cd6b9d]
 
pthread_create.c:0(start_thread)[0x7f8562e0eea5]
 
/lib64/libc.so.6(clone+0x6d)[0x7f85611af8dd]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x55af048b1ac0): select  FN_SPM_CHK_BCD_PUBL_TEST('1', '20200910') as aaa
 
Connection ID (thread ID): 11
 
Status: NOT_KILLED



 Comments   
Comment by Daniel Black [ 2020-10-07 ]

Nice bug report. Thanks. Can you attach the dump.sql? It seems to be missing despite your description.

Comment by Alice Sherepa [ 2020-10-07 ]

Repeatable on 10.3-10.5.
Please after the fix, check the initial test case, as I might oversimplified it.

delimiter |;
 
create function f2 () returns varchar(1) 
	begin
 
	DECLARE rec1 ROW TYPE OF v1;
 
	SELECT z into rec1 FROM v1;
 
	return 1;
 
END|
 
delimiter ;|
 
 
 
create function f1 () returns varchar(1) return f2() ;
 
create function f3 (a int) returns varchar(1) return f_not_exist();
 
create view  v1 as SELECT f3(1) z;
 
 
 
select f1();

10.3 d99f787244ab82f658b3f4

 
#3  <signal handler called>
 
#4  0x000056548d758162 in Item_sp::cleanup (this=0x7f3b58125fb8) at /10.3/sql/item.cc:2871
 
#5  0x000056548d7d0b8e in Item_func_sp::cleanup (this=0x7f3b58125ef8) at /10.3/sql/item_func.cc:6353
 
#6  0x000056548d41066d in cleanup_items (item=0x7f3b58125ef8) at /10.3/sql/sql_parse.cc:1155
 
#7  0x000056548d333773 in sp_head::execute (this=0x7f3b58124998, thd=0x7f3b58000d90, merge_da_on_success=true) at /10.3/sql/sp_head.cc:1468
 
#8  0x000056548d335346 in sp_head::execute_function (this=0x7f3b58124998, thd=0x7f3b58000d90, argp=0x0, argcount=0, return_value_fld=0x7f3b580188d8, func_ctx=0x7f3b58012e70, call_arena=0x7f3b58013fb8) at /10.3/sql/sp_head.cc:2122
 
#9  0x000056548d758752 in Item_sp::execute_impl (this=0x7f3b58012e10, thd=0x7f3b58000d90, args=0x0, arg_count=0) at /10.3/sql/item.cc:2995
 
#10 0x000056548d758311 in Item_sp::execute (this=0x7f3b58012e10, thd=0x7f3b58000d90, null_value=0x7f3b58012dc6, args=0x0, arg_count=0) at /10.3/sql/item.cc:2910
 
#11 0x000056548d7d0e23 in Item_func_sp::execute (this=0x7f3b58012d50) at /10.3/sql/item_func.cc:6412
 
#12 0x000056548d7d7690 in Item_func_sp::val_str (this=0x7f3b58012d50, str=0x7f3b69d331c0) at /10.3/sql/item_func.h:2959
 
#13 0x000056548d61ce09 in Type_handler::Item_send_str (this=0x56548eaeda08 <type_handler_varchar>, item=0x7f3b58012d50, protocol=0x7f3b58001348, buf=0x7f3b69d33190) at /10.3/sql/sql_type.cc:5387
 
#14 0x000056548d621bbe in Type_handler_string_result::Item_send (this=0x56548eaeda08 <type_handler_varchar>, item=0x7f3b58012d50, protocol=0x7f3b58001348, buf=0x7f3b69d33190) at /10.3/sql/sql_type.h:2252
 
#15 0x000056548d30703c in Item::send (this=0x7f3b58012d50, protocol=0x7f3b58001348, buffer=0x7f3b69d33190) at /10.3/sql/item.h:880
 
#16 0x000056548d3019f5 in Protocol::send_result_set_row (this=0x7f3b58001348, row_items=0x7f3b58005508) at /10.3/sql/protocol.cc:999
 
#17 0x000056548d3afcc0 in select_send::send_data (this=0x7f3b580182f8, items=...) at /10.3/sql/sql_class.cc:2942
 
#18 0x000056548d468260 in JOIN::exec_inner (this=0x7f3b58018320) at /10.3/sql/sql_select.cc:3991
 
#19 0x000056548d467c50 in JOIN::exec (this=0x7f3b58018320) at /10.3/sql/sql_select.cc:3910
 
#20 0x000056548d468f65 in mysql_select (thd=0x7f3b58000d90, tables=0x0, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7f3b580182f8, unit=0x7f3b58004c58, select_lex=0x7f3b580053e0) at /10.3/sql/sql_select.cc:4315
 
#21 0x000056548d45a537 in handle_select (thd=0x7f3b58000d90, lex=0x7f3b58004b98, result=0x7f3b580182f8, setup_tables_done_option=0) at /10.3/sql/sql_select.cc:370
 
#22 0x000056548d421b3d in execute_sqlcom_select (thd=0x7f3b58000d90, all_tables=0x0) at /10.3/sql/sql_parse.cc:6286
 
#23 0x000056548d418286 in mysql_execute_command (thd=0x7f3b58000d90) at /10.3/sql/sql_parse.cc:3812
 
#24 0x000056548d425e48 in mysql_parse (thd=0x7f3b58000d90, rawbuf=0x7f3b58012ab8 "select f1()", length=11, parser_state=0x7f3b69d34540, is_com_multi=false, is_next_command=false) at /10.3/sql/sql_parse.cc:7810
 
#25 0x000056548d41267d in dispatch_command (command=COM_QUERY, thd=0x7f3b58000d90, packet=0x7f3b58008f11 "", packet_length=11, is_com_multi=false, is_next_command=false) at /10.3/sql/sql_parse.cc:1847
 
#26 0x000056548d410f97 in do_command (thd=0x7f3b58000d90) at /10.3/sql/sql_parse.cc:1393
 
#27 0x000056548d58abe3 in do_handle_one_connection (connect=0x56548fd43e70) at /10.3/sql/sql_connect.cc:1403
 
#28 0x000056548d58a945 in handle_one_connection (arg=0x56548fd43e70) at /10.3/sql/sql_connect.cc:1308
 
#29 0x000056548df42575 in pfs_spawn_thread (arg=0x56548fd76260) at /10.3/storage/perfschema/pfs.cc:1869
 
#30 0x00007f3b70396609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#31 0x00007f3b6ff70293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Oleksandr Byelkin [ 2021-04-21 ]

SP trys to access memory to delete sp_result_field which was allocated in runtime arena of other sp and already deleted after execution of other (outer) SP.

Comment by Oleksandr Byelkin [ 2021-04-23 ]

The problem is also that there is 2 Item for f3 SP.

Comment by Oleksandr Byelkin [ 2021-04-23 ]

Problem is with Item_sp (f3) created by make_view, which allocates result firld in runtime of f2 function and cleaned up when the runtime root is already freed.

Comment by Oleksandr Byelkin [ 2021-04-26 ]

the test with no errors:

delimiter |;
 
create function f2 () returns varchar(1)
 
	begin
 
	DECLARE rec1 ROW TYPE OF v1;
 
	SELECT z into rec1 FROM v1;
 
	return 1;
 
END|
 
delimiter ;|
 
 
 
create function f1 () returns varchar(1) return f2() ;
 
create function f3 (a int) returns varchar(1) return "!";
 
create view  v1 as SELECT f3(1) z;
 
 
 
select f1();
 
 
 
drop function f3;
 
drop function f2;
 
drop function f1;
 
 
 
drop view v1;

on 10.2 can not be reproduced because "ROW TYPE OF v1" is important but it is absent in 10.2.

Comment by Dmitry Shulga [ 2023-07-20 ]

A patch for review is pushed to the branch bb-10.4-MDEV-23902

Comment by Oleksandr Byelkin [ 2023-07-26 ]

I do not see how it avoud memory leak by allocatiing it only once, have you checked it?

Comment by Oleksandr Byelkin [ 2023-09-18 ]

OK to push

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