[MDEV-29320] MariaDB server crashes in Item::save_in_field() when executing stored procedure Created: 2022-08-17  Updated: 2022-09-26  Resolved: 2022-09-26

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

Type: Bug Priority: Major
Reporter: Valerii Kravchuk Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: crash, stored_procedures

Issue Links:
Relates
relates to MDEV-15545 crash 11 during evaluating an expression Closed

 Description   

The following crash happens for customer:

220815 22:58:47 [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.34-MariaDB-log
key_buffer_size=67108864
read_buffer_size=131072
max_used_connections=58
max_threads=1002
thread_count=59
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2313574 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7fb770058b18
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 = 0x7fb8641a8d30 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55f9cdea036e]
/usr/sbin/mysqld(handle_fatal_signal+0x30f)[0x55f9cd93495f]
/lib64/libpthread.so.0(+0xf630)[0x7fc268d0a630]
/usr/sbin/mysqld(_ZN4Item13save_in_fieldEP5Fieldb+0x4a)[0x55f9cd94983a]
/usr/sbin/mysqld(_ZN5Field25sp_prepare_and_store_itemEP3THDPP4Item+0x53)[0x55f9cd9154a3]
/usr/sbin/mysqld(_ZN3THD12sp_eval_exprEP5FieldPP4Item+0x57)[0x55f9cd6ba9c7]
/usr/sbin/mysqld(_ZN11sp_rcontext12set_variableEP3THDjPP4Item+0x23)[0x55f9cd6c8ac3]
/usr/sbin/mysqld(_ZN12sp_instr_set9exec_coreEP3THDPj+0x2f)[0x55f9cd6c143f]
/usr/sbin/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x2f9)[0x55f9cd6c08b9]
/usr/sbin/mysqld(_ZN7sp_head7executeEP3THDb+0x897)[0x55f9cd6bc547]
/usr/sbin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x74d)[0x55f9cd6bd7bd]
/usr/sbin/mysqld(+0x5d0882)[0x55f9cd744882]
/usr/sbin/mysqld(+0x5d2826)[0x55f9cd746826]
/usr/sbin/mysqld(_ZN12Sql_cmd_call7executeEP3THD+0x90)[0x55f9cd747060]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x137a)[0x55f9cd74dfca]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x1fb)[0x55f9cd75584b]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x106c)[0x55f9cd7571bc]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x11b)[0x55f9cd75943b]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x1d6)[0x55f9cd830ac6]
/usr/sbin/mysqld(handle_one_connection+0x3d)[0x55f9cd830bdd]
/lib64/libpthread.so.0(+0x7ea5)[0x7fc268d02ea5]
/lib64/libc.so.6(clone+0x6d)[0x7fc268a2b98d]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7fb770013a60): call DB.SOME_PROC()
 
Connection ID (thread ID): 2038403
Status: NOT_KILLED
...

In the full backtrace we see:

Thread 1 (Thread 0x7fb8641a9700 (LWP 7442)):
#0  0x00007fc268d07aa1 in pthread_kill () from /lib64/libpthread.so.0
No symbol table info available.
#1  0x000055f9cd9349de in handle_fatal_signal (sig=11) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/signal_handler.cc:355
        curr_time = 1660575527
        tm = {tm_sec = 47, tm_min = 58, tm_hour = 22, tm_mday = 15, tm_mon = 7, tm_year = 122, tm_wday = 1, tm_yday = 226, tm_isdst = 0, tm_gmtoff = 28800, tm_zone = 0x55f9cfe59680 "+08"}
        print_invalid_query_pointer = false
#2  <signal handler called>
No symbol table info available.
#3  Item::save_in_field (this=0x7fb7721d73d0, field=0x7fb77032f228, no_conversions=<optimized out>) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/item.cc:7001
        this = 0x7fb7721d73d0
        no_conversions = false
        field = 0x7fb77032f228
#4  0x000055f9cd9154a3 in Field::sp_prepare_and_store_item (this=0x7fb77032f228, thd=0x7fb770058b18, value=<optimized out>) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/field.cc:1357
No locals.
#5  0x000055f9cd6ba9c7 in THD::sp_eval_expr (this=this@entry=0x7fb770058b18, result_field=<optimized out>, expr_item_ptr=expr_item_ptr@entry=0x7fb7721d7508) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sp_head.cc:415
        state = {m_thd = 0x7fb770058b18, m_count_cuted_fields = CHECK_FIELD_IGNORE, m_abort_on_warning = false, m_stmt_modified_non_trans_table = false}
#6  0x000055f9cd6c8ac3 in sp_rcontext::set_variable (this=<optimized out>, thd=thd@entry=0x7fb770058b18, idx=idx@entry=1, value=value@entry=0x7fb7721d7508) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sp_rcontext.cc:623
No locals.
#7  0x000055f9cd6c143f in sp_instr_set::exec_core (this=0x7fb7721d74c0, thd=0x7fb770058b18, nextp=0x7fb8641a61b0) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sp_head.cc:3737
        res = <optimized out>
#8  0x000055f9cd6c08b9 in sp_lex_keeper::reset_lex_and_exec_core (this=0x7fb7721d7510, thd=0x7fb770058b18, nextp=0x7fb8641a61b0, open_tables=<optimized out>, instr=0x7fb7721d74c0) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sp_head.cc:3438
        res = <optimized out>
        parent_modified_non_trans_table = false
        parent_unsafe_rollback_flags = 0
#9  0x000055f9cd6bc547 in sp_head::execute (this=this@entry=0x7fb770aba310, thd=thd@entry=0x7fb770058b18, merge_da_on_success=merge_da_on_success@entry=true) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sp_head.cc:1377
        parent_digest = 0x7fb77005c1c8
        saved_cur_db_name_buf = "\300c\032d\270\177\000\000\202\203l\315\371U\000\000\320c\032d\270\177\000\000\060d\032d\270\177\000\000\000\000\000\000\000\000\000\000\020\243\253p\267\177\000\000\030\213\005p\267\177\000\000\020\243\253p\267\177\000\000\000\000\000\000\000\000\000\000\060d\032d\270\177\000\000 d\032d\270\177\000\000H\313k\315\371U\000\000 d\032d\270\177\000\000\334kl\315\371U\000\000@d\032d\270\177\000\000\302\232p\315\371U\000\000\000\000\000\000\000\000\000\000\060\243\253p\267\177\000\000\060\243\253p\267\177\000\000襫p\267\177\000\000\000\000\000\000\000\000\000\000\020\243\253p\267\177\000\000\360d\032d\270\177\000\000\030\213\005p\267\177\000\000襫p\267\177\000\000\001"
        saved_cur_db_name = {str = 0x0, length = 0}
        ctx = 0x7fb77032dfa0
        execute_mem_root = {free = 0x0, used = 0x0, pre_alloc = 0x0, min_malloc = 32, block_size = 8152, total_alloc = 0, block_num = 4, first_block_usage = 0, error_handler = 0x55f9cd80e950 <sql_alloc_error_handler()>, name = 0x55f9cdf24181 "per_instruction_memroot"}
        old_query_id = 3966003692
        old_rec_tables = 0x0
        old_change_list = {change_list = {<base_ilist> = {first = 0x7fb770058bd0, last = {_vptr.ilink = 0x55f9ce6c4cd0 <vtable for ilink+16>, prev = 0x7fb770058bc8, next = 0x0}}, <No data fields>}}
        ip = 80
        saved_creation_ctx = 0x7fb6656cb050
        cur_db_changed = true
        err_status = false
        execute_arena = {_vptr.Query_arena = 0x55f9ce6cb470 <vtable for Query_arena+16>, free_list = 0x0, mem_root = 0x7fb8641a6260, state = Query_arena::STMT_INITIALIZED_FOR_SP}
        backup_arena = {_vptr.Query_arena = 0x55f9ce6cb470 <vtable for Query_arena+16>, free_list = 0x7fb7723bf960, mem_root = 0x7fb77005dec0, state = Query_arena::STMT_CONVENTIONAL_EXECUTION}
        old_lex = 0x7fb77005c748
        status_backup_mask = 192
        user_var_events_alloc_saved = 0x7fb77005dec0
        i = 0x7fb7721d74c0
        old_derived_tables = 0x0
        old_server_status = 0
        save_abort_on_warning = false
        old_arena = 0x7fb770058b30
        old_packet = {<Sql_alloc> = {<No data fields>}, Ptr = 0x7fb77000f8c8 "\001\060ef", str_length = 2, Alloced_length = 16392, extra_alloc = 0, alloced = true, thread_specific = false, str_charset = 0x55f9ce8094e0 <my_charset_bin>}
        save_reprepare_observer = 0x0
        save_sql_mode = 8860525070
        da = 0x7fb77005df08
        sp_wi = {m_warn_root = {free = 0x0, used = 0x0, pre_alloc = 0x0, min_malloc = 32, block_size = 2009, total_alloc = 0, block_num = 4, first_block_usage = 0, error_handler = 0x55f9cd80e950 <sql_alloc_error_handler()>, name = 0x55f9cdf25cf4 "Warning_info"}, m_warn_list = {<I_P_List_counter> = {m_counter = 0}, <I_P_List_fast_push_back<Sql_condition>> = {m_last = 0x7fb8641a6308}, m_first = 0x0}, m_warn_count = {0, 0, 0}, m_current_statement_warn_count = 0, m_current_row_for_warning = 26, m_warn_id = 3966015501, m_error_condition = 0x0, m_allow_unlimited_warnings = false, initialized = true, m_read_only = false, m_next_in_da = 0x7fb77005e148, m_prev_in_da = 0x7fb77005e210, m_marked_sql_conditions = {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x55f9ce8843e0 <end_of_list>, last = 0x7fb8641a6350, elements = 0}, <No data fields>}}
#10 0x000055f9cd6bd7bd in sp_head::execute_procedure (this=0x7fb770aba310, thd=thd@entry=0x7fb770058b18, args=0x7fb77005d5f8) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sp_head.cc:2404
        params = <optimized out>
        save_spcont = 0x0
        nctx = 0x7fb77032dfa0
        octx = 0x7fb770018818
        save_log_general = true
        need_binlog_call = <optimized out>
        err_status = false
        utime_before_sp_exec = 12249565017655
        save_enable_slow_log = true
        pkg = 0x0
        save_security_ctx = 0x0
#11 0x000055f9cd744882 in do_execute_sp (thd=0x7fb770058b18, sp=<optimized out>) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_parse.cc:3019
        bits_to_be_cleared = <optimized out>
        affected_rows = <optimized out>
        select_limit = 18446744073709551615
        res = <optimized out>
        sp = <optimized out>
        thd = 0x7fb770058b18
#12 0x000055f9cd746826 in Sql_cmd_call::execute (this=this@entry=0x7fb770013b60, thd=thd@entry=0x7fb770058b18) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_parse.cc:3259
        sp = 0x7fb770aba310
#13 0x000055f9cd747060 in Sql_cmd_call::execute (this=0x7fb770013b60, thd=0x7fb770058b18) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_parse.cc:3213
No locals.
#14 0x000055f9cd74dfca in mysql_execute_command (thd=thd@entry=0x7fb770058b18) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_parse.cc:6075
        res = 0
        lex = 0x7fb77005c748
        orig_binlog_format = BINLOG_FORMAT_ROW
        up_result = 0
        rpl_filter = <optimized out>
        orig_current_stmt_binlog_format = BINLOG_FORMAT_ROW
        select_lex = 0x7fb77005cfa0
        first_table = 0x0
        all_tables = 0x0
        unit = 0x7fb77005c808
        have_table_map_for_update = false
#15 0x000055f9cd75584b in mysql_parse (thd=thd@entry=0x7fb770058b18, rawbuf=<optimized out>, length=32, parser_state=parser_state@entry=0x7fb8641a84d0, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_parse.cc:7870
        found_semicolon = <optimized out>
        error = <optimized out>
        lex = 0x7fb77005c748
        err = <optimized out>
#16 0x000055f9cd7571bc in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fb770058b18, packet=packet@entry=0x7fb77005e569 "call DB.SOME_PROC()", packet_length=packet_length@entry=32, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_parse.cc:1853
        packet_end = 0x7fb770013a80 ""
        parser_state = {m_lip = {lookahead_token = -1, lookahead_yylval = 0x0, m_thd = 0x7fb770058b18, m_ptr = 0x7fb770013a81 "", m_tok_start = 0x7fb770013a81 "", m_tok_end = 0x7fb770013a81 "", m_end_of_query = 0x7fb770013a80 "", m_tok_start_prev = 0x7fb770013a80 "", m_buf = 0x7fb770013a60 "call DB.SOME_PROC()", m_buf_length = 32, m_echo = true, m_echo_saved = 135, m_cpp_buf = 0x7fb770013ad8 "call DB.SOME_PROC()", m_cpp_ptr = 0x7fb770013af8 "", m_cpp_tok_start = 0x7fb770013af8 "", m_cpp_tok_start_prev = 0x7fb770013af8 "", m_cpp_tok_end = 0x7fb770013af8 "", m_body_utf8 = 0x0, m_body_utf8_ptr = 0xc21deaa10d0d3700 <Address 0xc21deaa10d0d3700 out of bounds>, m_cpp_utf8_processed_ptr = 0x0, next_state = MY_LEX_END, found_semicolon = 0x0, ignore_space = true, stmt_prepare_mode = false, multi_statements = true, yylineno = 1, m_digest = 0x0, in_comment = NO_COMMENT, in_comment_saved = (DISCARD_COMMENT | unknown: 32704), m_cpp_text_start = 0x7fb770013ae3 "SOME_PROC()", m_cpp_text_end = 0x7fb770013af6 "()", m_underscore_cs = 0x0}, m_yacc = {yacc_yyss = 0x0, yacc_yyvs = 0x0, m_set_signal_info = {m_item = {0x0 <repeats 12 times>}}, m_lock_type = TL_READ_DEFAULT, m_mdl_type = MDL_SHARED_READ}, m_digest_psi = 0x0}
        net = 0x7fb770058d78
        error = false
        do_end_of_statement = true
        drop_more_results = false
#17 0x000055f9cd75943b in do_command (thd=0x7fb770058b18) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_parse.cc:1399
        return_value = <optimized out>
        packet = 0x7fb77005e568 "\003call DB.SOME_PROC()"
        packet_length = 33
        net = 0x7fb770058d78
        command = COM_QUERY
#18 0x000055f9cd830ac6 in do_handle_one_connection (connect=connect@entry=0x55fa0331a4f8) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_connect.cc:1403
        create_user = true
        thr_create_utime = <optimized out>
        thd = 0x7fb770058b18
#19 0x000055f9cd830bdd in handle_one_connection (arg=0x55fa0331a4f8) at /usr/src/debug/MariaDB-10.3.34/src_0/sql/sql_connect.cc:1308
        connect = 0x55fa0331a4f8
#20 0x00007fc268d02ea5 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#21 0x00007fc268a2b98d in clone () from /lib64/libc.so.6
No symbol table info available.

I can not find any existing bug report with similar backtrace, hence this new one.


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