Assert on KILL'ing a stored routine invocation | Assertion `m_status == DA_ERROR' failed.

Bug #1689736 reported by Laurynas Biveinis on 2017-05-10
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
Invalid
Undecided
Unassigned
5.6
Fix Released
High
Laurynas Biveinis
5.7
Fix Released
High
Laurynas Biveinis

Bug Description

Source code patch for debug sync:

diff --git a/sql/sp_instr.cc b/sql/sp_instr.cc
index 2de6c99bc56..ea12e9f9b94 100644
--- a/sql/sp_instr.cc
+++ b/sql/sp_instr.cc
@@ -28,6 +28,7 @@
 #include "sql_prepare.h" // reinit_stmt_before_use
 #include "transaction.h" // trans_commit_stmt
 #include "sql_audit.h"
+#include "debug_sync.h" // DEBUG_SYNC

 #include <algorithm>

@@ -397,6 +398,8 @@ bool sp_lex_instr::reset_lex_and_exec_core(THD *thd,
   }
   else
   {
+ DEBUG_SYNC(thd, "sp_lex_instr_before_exec_core");
+
     rc= exec_core(thd, nextp);
     DBUG_PRINT("info",("exec_core returned: %d", rc));
   }

MTR testcase:

--source include/have_debug_sync.inc
--source include/count_sessions.inc

CREATE TABLE t1 (a INT);

DELIMITER |;

CREATE FUNCTION f1() RETURNS INT
BEGIN
  INSERT INTO t1 VALUES (1);
  RETURN 1;
END|

DELIMITER ;|

--connect(con1,localhost,root)

--connection default
--let $sp_con_id= `SELECT CONNECTION_ID()`
SET DEBUG_SYNC= "sp_lex_instr_before_exec_core SIGNAL sp_ready WAIT_FOR sp_finish";
send SELECT f1();

--connection con1
SET DEBUG_SYNC="now WAIT_FOR sp_ready";
--replace_result $sp_con_id sp_con_id
--eval KILL $sp_con_id
SET DEBUG_SYNC="now SIGNAL sp_finish";

--connection default
reap;

disconnect con1;

--source include/wait_until_count_sessions.inc

Results in:

Assertion failed: (m_status == DA_ERROR), function sql_errno, file /Users/laurynas/percona/mysql-server/sql/sql_error.h, line 655.
06:28:11 UTC - mysqld got signal 6 ;
...
  thread #20, stop reason = signal SIGSTOP
    frame #0: 0x00007fffcb217d42 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fffcb3055bf libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x0000000101811e9b mysqld-debug`my_write_core(sig=6) at stacktrace.c:424
    frame #3: 0x0000000101450dd3 mysqld-debug`::handle_fatal_signal(sig=6) at signal_handler.cc:236
    frame #4: 0x00007fffcb2f8b3a libsystem_platform.dylib`_sigtramp + 26
    frame #5: 0x00007fffcb217d43 libsystem_kernel.dylib`__pthread_kill + 11
    frame #6: 0x00007fffcb3055bf libsystem_pthread.dylib`pthread_kill + 90
    frame #7: 0x00007fffcb17d420 libsystem_c.dylib`abort + 129
    frame #8: 0x00007fffcb144893 libsystem_c.dylib`__assert_rtn + 320
    frame #9: 0x00000001012c3500 mysqld-debug`Diagnostics_area::sql_errno(this=0x00007fb07f953610) const at sql_error.h:655
    frame #10: 0x0000000101462bac mysqld-debug`sp_lex_instr::reset_lex_and_exec_core(this=0x00007fb083803388, thd=0x00007fb07f950000, nextp=0x0000700008a491f8, open_tables=false) at sp_instr.cc:461
    frame #11: 0x0000000101463631 mysqld-debug`sp_lex_instr::validate_lex_and_execute_core(this=0x00007fb083803388, thd=0x00007fb07f950000, nextp=0x0000700008a491f8, open_tables=false) at sp_instr.cc:689
    frame #12: 0x0000000101463c1d mysqld-debug`sp_instr_stmt::execute(this=0x00007fb083803388, thd=0x00007fb07f950000, nextp=0x0000700008a491f8) at sp_instr.cc:879
    frame #13: 0x000000010145be77 mysqld-debug`sp_head::execute(this=0x00007fb083801610, thd=0x00007fb07f950000, merge_da_on_success=true) at sp_head.cc:649
    frame #14: 0x000000010145d7ac mysqld-debug`sp_head::execute_function(this=0x00007fb083801610, thd=0x00007fb07f950000, argp=0x8f8f8f8f8f8f8f8f, argcount=0, return_value_fld=0x00007fb0800ab1e8) at sp_head.cc:1097
    frame #15: 0x000000010136a5ab mysqld-debug`Item_func_sp::execute_impl(this=0x00007fb0800a96b0, thd=0x00007fb07f950000) at item_func.cc:6992
    frame #16: 0x000000010136a2ea mysqld-debug`Item_func_sp::execute(this=0x00007fb0800a96b0) at item_func.cc:6921
    frame #17: 0x000000010136e899 mysqld-debug`Item_func_sp::val_int(this=0x00007fb0800a96b0) at item_func.h:2130
    frame #18: 0x00000001012f520a mysqld-debug`Item::send(this=0x00007fb0800a96b0, protocol=0x00007fb07f950590, buffer=0x0000700008a4a718) at item.cc:6925
    frame #19: 0x0000000101445b47 mysqld-debug`Protocol::send_result_set_row(this=0x00007fb07f950590, row_items=0x00007fb07f952b68) at protocol.cc:844
    frame #20: 0x00000001014f112a mysqld-debug`select_send::send_data(this=0x00007fb0800aad30, items=0x00007fb07f952b68) at sql_class.cc:2773
    frame #21: 0x00000001015157fa mysqld-debug`JOIN::exec(this=0x00007fb0800aad58) at sql_executor.cc:151
    frame #22: 0x00000001015ea2d6 mysqld-debug`mysql_execute_select(thd=0x00007fb07f950000, select_lex=0x00007fb07f952a48, free_join=true) at sql_select.cc:1105
    frame #23: 0x00000001015e88c5 mysqld-debug`mysql_select(thd=0x00007fb07f950000, tables=0x0000000000000000, wild_num=0, fields=0x00007fb07f952b68, conds=0x0000000000000000, order=0x00007fb07f952c10, group=0x00007fb07f952b48, having=0x0000000000000000, select_options=2147748608, result=0x00007fb0800aad30, unit=0x00007fb07f952400, select_lex=0x00007fb07f952a48) at sql_select.cc:1226
    frame #24: 0x00000001015e84d1 mysqld-debug`handle_select(thd=0x00007fb07f950000, result=0x00007fb0800aad30, setup_tables_done_option=0) at sql_select.cc:101
    frame #25: 0x000000010158f7ed mysqld-debug`execute_sqlcom_select(thd=0x00007fb07f950000, all_tables=0x0000000000000000) at sql_parse.cc:5772
    frame #26: 0x00000001015843f4 mysqld-debug`mysql_execute_command(thd=0x00007fb07f950000) at sql_parse.cc:3055
    frame #27: 0x0000000101580e78 mysqld-debug`mysql_parse(thd=0x00007fb07f950000, rawbuf="SELECT f1()", length=11, parser_state=0x0000700008a4e380) at sql_parse.cc:7058
    frame #28: 0x000000010157d72b mysqld-debug`dispatch_command(command=COM_QUERY, thd=0x00007fb07f950000, packet="", packet_length=11) at sql_parse.cc:1485
    frame #29: 0x000000010158029c mysqld-debug`do_command(thd=0x00007fb07f950000) at sql_parse.cc:1062
    frame #30: 0x0000000101503908 mysqld-debug`do_handle_one_connection(thd_arg=0x00007fb081084000) at sql_connect.cc:1550
    frame #31: 0x000000010150362d mysqld-debug`::handle_one_connection(arg=0x00007fb081084000) at sql_connect.cc:1454
    frame #32: 0x0000000101c151ad mysqld-debug`::pfs_spawn_thread(arg=0x00007fb07f61f0f0) at pfs.cc:1860
    frame #33: 0x00007fffcb3029af libsystem_pthread.dylib`_pthread_body + 180
    frame #34: 0x00007fffcb3028fb libsystem_pthread.dylib`_pthread_start + 286
    frame #35: 0x00007fffcb302101 libsystem_pthread.dylib`thread_start + 13

Seen as an intermittent main.max_statement_time_func failure:

main.max_statement_time_func w1 [ fail ]
        Test ended at 2017-05-03 09:49:13

CURRENT_TEST: main.max_statement_time_func
mysqltest: At line 63: query 'SELECT f1()' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 1886...

tags: added: upstream
tags: added: regression
summary: - Assert on KILL'ing a stored routine invocation
+ Assert on KILL'ing a stored routine invocation | Assertion `m_status ==
+ DA_ERROR' failed.

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1091

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.