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

[Laurynas Biveinis]

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

[Laurynas Biveinis (laurynas-biveinis)]

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...

[Laurynas Biveinis (laurynas-biveinis)]

     https://github.com/percona/percona-server/pull/1716
     https://github.com/percona/percona-server/pull/1717
     https://github.com/percona/percona-server/pull/1718

[Shahriyar Rzayev (rzayev-sehriyar)]

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