| Bug #27563 | killing noticed in SF() stack but the error gets missed in action and wrong rslt | ||
|---|---|---|---|
| Submitted: | 31 Mar 2007 14:09 | Modified: | 18 Jun 2007 17:57 |
| Reporter: | Andrei Elkin | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Stored Routines | Severity: | S3 (Non-critical) |
| Version: | 5.0.38 | OS: | Any |
| Assigned to: | Evgeny Potemkin | CPU Architecture: | Any |
[31 Mar 2007 15:32]
Andrei Elkin
An interesting and harmful(!!!) pecularity of the bug is that what actually got inserted is wrong: mysql> select * from t1; +---+------+ | a | b | +---+------+ | 2 | 1 | +---+------+ To get to this I modified bug22725() to use SELECT: create function bug22725() RETURNS int(11) DETERMINISTIC begin select get_lock("a", 10) into @a; return 1; end| delimiter ;| How to repeat remains the same, but instead of (1,1) in the table t1 there is (2,1).
[31 Mar 2007 17:24]
Andrei Elkin
And one more artifact to gather: the client of the connection of killed query does not get any messages despite thd->killed is KILL_QUERY after mysql_insert() (i checked mysql_update() too) finishes. There is something that blocks client error generation.
[31 Mar 2007 19:00]
Andrei Elkin
Missed query killed error to the client might relate to another Bug #27565 killed query of SF() is not reported correctly
[20 Apr 2007 9:30]
Sveta Smirnova
Thank you for the report.
Original description verified as described using last BK sources.
gdb output:
(gdb) br sp_head::execute
Breakpoint 2 at 0x83b1bcf: file sp_head.cc, line 908.
(gdb) c
Continuing.
[New Thread -1297257552 (LWP 943)]
[New Thread -1297458256 (LWP 944)]
[Switching to Thread -1297458256 (LWP 944)]
Breakpoint 2, sp_head::execute (this=0xa383270, thd=0xa3729d8) at sp_head.cc:908
908 DBUG_ENTER("sp_head::execute");
(gdb) fin
Run till exit from #0 sp_head::execute (this=0xa383270, thd=0xa3729d8) at sp_head.cc:908
0x083b7553 in sp_head::execute_function (this=0xa383270, thd=0xa3729d8, argp=0x8f8f8f8f, argcount=0, return_value_fld=0xa37cf30) at sp_head.cc:1505
1505 err_status= execute(thd);
Value returned is $1 = true
(gdb) bt
#0 0x083b7553 in sp_head::execute_function (this=0xa383270, thd=0xa3729d8, argp=0x8f8f8f8f, argcount=0, return_value_fld=0xa37cf30) at sp_head.cc:1505
#1 0x081acb8c in Item_func_sp::execute_impl (this=0xa37c4b0, thd=0xa3729d8) at item_func.cc:5222
#2 0x081acbfc in Item_func_sp::execute (this=0xa37c4b0) at item_func.cc:5170
#3 0x081af025 in Item_func_sp::val_int (this=0xa37c4b0) at item_func.h:1444
#4 0x0817eb3f in Item::save_in_field (this=0xa37c4b0, field=0xa38ada8, no_conversions=false) at item.cc:4419
#5 0x0826b182 in fill_record (thd=0xa3729d8, ptr=0xa38ad7c, values=@0xa37c428, ignore_errors=false) at sql_base.cc:5448
#6 0x0826b247 in fill_record_n_invoke_before_triggers (thd=0xa3729d8, ptr=0xa38ad78, values=@0xa37c428, ignore_errors=false, triggers=0x0, event=TRG_EVENT_INSERT) at sql_base.cc:5491
#7 0x082a50c1 in mysql_insert (thd=0xa3729d8, table_list=0xa37c280, fields=@0xa373be4, values_list=@0xa373c08, update_fields=@0xa373bfc, update_values=@0xa373bf0, duplic=DUP_ERROR, ignore=false)
at sql_insert.cc:679
#8 0x0823ac90 in mysql_execute_command (thd=0xa3729d8) at sql_parse.cc:3499
#9 0x08240579 in mysql_parse (thd=0xa3729d8, inBuf=0xa37c1f0 "insert into t1 values (bug22725(),1)", length=36) at sql_parse.cc:6018
#10 0x08241078 in dispatch_command (command=COM_QUERY, thd=0xa3729d8, packet=0xa374051 "insert into t1 values (bug22725(),1)", packet_length=37) at sql_parse.cc:1802
#11 0x082425e1 in do_command (thd=0xa3729d8) at sql_parse.cc:1581
#12 0x08242ace in handle_one_connection (arg=0xa3729d8) at sql_parse.cc:1193
#13 0x0045fbd4 in start_thread () from /lib/libpthread.so.0
#14 0x003b74fe in clone () from /lib/libc.so.6
(gdb) info f 4
Stack frame at 0xb2aa4150:
eip = 0x817eb3f in Item::save_in_field(Field*, bool) (item.cc:4419); saved eip 0x826b182
called by frame at 0xb2aa41b0, caller of frame at 0xb2aa3df0
source language c++.
Arglist at 0xb2aa4148, args: this=0xa37c4b0, field=0xa38ada8, no_conversions=false
Locals at 0xb2aa4148, Previous frame's sp is 0xb2aa4150
Saved registers:
ebx at 0xb2aa4140, ebp at 0xb2aa4148, esi at 0xb2aa4144, eip at 0xb2aa414c
(gdb) f 4
#4 0x0817eb3f in Item::save_in_field (this=0xa37c4b0, field=0xa38ada8, no_conversions=false) at item.cc:4419
4419 longlong nr=val_int();
(gdb) print nr
$2 = 583467835530559816
Problem with SELECT is not repeatable in my environment.
[23 May 2007 14:03]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/27218 ChangeSet@1.2493, 2007-05-23 18:00:43+04:00, evgen@moonbone.local +5 -0 Bug#27563: Stored functions and triggers wasn't throwing an error when killed. If a stored function or a trigger was killed it had aborted but no error was thrown. This allows the caller statement to continue without a notice. This may lead to a wrong data being inserted/updated to/deleted as in such cases the correct result of a stored function isn't guaranteed. In the case of triggers it allows the caller statement to ignore of kill signal and to waste of time because of re-evaluation of triggers that always will fail due to thd->killed flag still set. Now the Item_func_sp::execute() and the sp_head::execute_trigger() functions are checking whether a function or a trigger were killed during execution and throws an appropriate error if so. Now the fill_record() function stops filling record if an error was reported through thd->net.report_error.
[23 May 2007 19:27]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/27236 ChangeSet@1.2493, 2007-05-23 23:24:16+04:00, evgen@moonbone.local +5 -0 Bug#27563: Stored functions and triggers wasn't throwing an error when killed. If a stored function or a trigger was killed it had aborted but no error was thrown. This allows the caller statement to continue without a notice. This may lead to a wrong data being inserted/updated to/deleted as in such cases the correct result of a stored function isn't guaranteed. In the case of triggers it allows the caller statement to ignore kill signal and to waste time because of re-evaluation of triggers that always will fail because thd->killed flag is still on. Now the Item_func_sp::execute() and the sp_head::execute_trigger() functions check whether a function or a trigger were killed during execution and throws an appropriate error if so. Now the fill_record() function stops filling record if an error was reported through thd->net.report_error.
[4 Jun 2007 21:21]
Bugs System
Pushed into 5.1.20-beta
[4 Jun 2007 21:23]
Bugs System
Pushed into 5.0.44
[18 Jun 2007 17:57]
Paul DuBois
Noted in 5.0.44, 5.1.20 changelogs.
[3 Aug 2007 15:36]
Konstantin Osipov
Bug #27550 No error message if a query was interrupted with KILL QUERY statement was marked a duplicate of this bug.
[3 Aug 2007 15:38]
Konstantin Osipov
Bug #27565 killed query of SF() is not reported correctly was marked a duplicate of this bug.
Description: if the query gets killed while executing the body of a SF() we can see that the error due to thd->killed == KILLED_QUERY is noticed and starts to be propagated upward the stack: #0 sp_head::execute (this=0x8be2de8, thd=0x8bbdbf8) at sp_head.cc:1046 #1 0x08304d3c in sp_head::execute_function (this=0x8be2de8, thd=0x8bbdbf8, argp=0x8f8f8f8f, argcount=0, return_value_fld=0x8bd3b70) at sp_head.cc:1499 #2 0x0813b1cc in Item_func_sp::execute_impl (this=0x8bd3088, thd=0x8bbdbf8, return_value_fld=0x8bd3b70) at item_func.cc:5171 #3 0x081411e8 in Item_func_sp::execute (this=0x8bd3088, flp=0x8bd310c) at item_func.cc:5129 #4 0x081477b6 in Item_func_sp::val_int (this=0x8bd3088) at item_func.h:1441 Run till exit from #0 0x081411e8 in Item_func_sp::execute (this=0x8bd3088, flp=0x8bd310c) at item_func.cc:5129 0x081477b6 in Item_func_sp::val_int (this=0x8bd3088) at item_func.h:1441 Value returned is $9 = true the error was caught --^ ~~~~~~~~~~~~~~~~~~~~~~~~ However, it gets slipped away in #5 0x0811e640 in Item::save_in_field (this=0x8bd3088, field=0x8ba1980, no_conversions=false) at item.cc:4421 { longlong nr=val_int(); // <- there was the error, but the following code // does not propagate it anymore if (null_value) return set_field_to_null_with_conversions(field, no_conversions); where INSERT work continues using the result of SF() and the query completes despite SF()'s GET_LOCK got killed. This artifact might stand in the way of fixing bug#22725. How to repeat: delimiter |; create function bug22725() RETURNS int(11) DETERMINISTIC begin set @a= get_lock("a", 100); return 1; end| delimiter ;| --enable_info create table t1 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=InnoDB; create table t2 (a int auto_increment, b int, PRIMARY KEY (a)) ENGINE=MyISAM; --disable_info reset master; # ta table case: killing cause rollback # a - autocommit ON connection con1; select get_lock("a", 100); (gdb) br sp_head::execute connection con2; let $ID= `select connection_id()`; send insert into t1 values (bug22725(),1); (gdb) fin # and trace propagation of the error when con2 gets active; the error gets # dropped off as described # to inflict early exit by con2 from sp_head::execute with the error connection con1; eval kill query $ID; Suggested fix: Looks like the logic of propagation like in sub_select \ evaluate_join_record if (error > 0 || (*report_error)) // Fatal error return NESTED_LOOP_ERROR; does not apply always.