Bug #27571 asynchronousity in setting mysql_`query`::error and Query_log_event::error_code
Submitted: 1 Apr 2007 11:59 Modified: 23 Jan 2008 18:48
Reporter: Andrei Elkin Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:5.0.38, 5.1.18 OS:Any
Assigned to: Andrei Elkin CPU Architecture:Any

[1 Apr 2007 11:59] Andrei Elkin
Description:
A query can perform completely having the local var error of mysql_$query zero,
where $query in insert, update, delete, load,
and be  binlogged with error_code e.g KILLED_QUERY while there is no reason do to so.
That can happen because Query_log_event consults thd->killed flag to evaluate
error_code. The flag might be externally modified so that we can have a situation similar to bug#22725 (which is a separate issue, because thd->killed
is not consulted in evaluation of mysql_insert::error).

The current logic is
1. mysql_query sets

      error= f(thd->killed), 
      f  some evaluation form depending on the flag 

2. in mysql_query functions call Query_log_event() that
   
      evaluate error_code as g(error, thd->killed),  
      g some evaluation form depending on the flag and error

Since there are two different times when thd->killed flag was queried
we can have incorrect binlogging.
     

How to repeat:
1. Look at the code; 
2. Look at bug#22725 symptoms: query on ta-table with killed error.
3. it can be inspired easy with gdb: 

create table t1 (a int) engine=innodb;
insert into t1 values (1,2,3,4,5);

# set br at the line of mysql_update() with
# if ((error < 0) || (updated && !transactional_table)), 
(gdb) br sql_update.cc:536
update t1 set a = a+1;

(gdb) set thd->killed = KILL_QUERY; 
#  considering the logic of several line above:
#  if (thd->killed && !error)
#    error= 1;					// Aborted

the query would be aborted if thd->killed set several instruction earlier, but now it goes into binlogging section.

Suggested fix:
Todo:

     change the constuctor Query_log_event() so that it should accept
     error_code as an argument.

     error_code should be evaluated basing on only error which in its turn
     has consulted thd->killed:

     Query_log_event::error_code -> mysql_query::error -> thd->killed
[4 Apr 2007 11:27] Andrei Elkin
comments added to sql_update.cc of bug22725 patch 

  /*
    todo bug#27571: to avoid asyncronization of `error' and
    `error_code' of binlog event constructor
    to change  error_code argument evaluation in step with `error'
    so that event's constructor accepts `binlog_error_code' as an argument
    The concept:

    binlog_error_code= thd->killed? thd->killed_errno() :
                                    error? thd->net.last_errno : 0;
    error= (binlog_error_code != 0);

    Applies to most mysql_$query functions.
  */

  if (thd->killed && !error)
    error= 1;					// Aborted
[10 Apr 2007 9:11] Sveta Smirnova
Thank you for the report.

Verified as described.
[16 Oct 2007 14:54] 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/35660

ChangeSet@1.2542, 2007-10-16 17:52:54+03:00, aelkin@dsl-hkibras1-ff5fc300-23.dhcp.inet.fi +5 -0
  Bug #27571 asynchronousity in setting mysql_`query`::error and Query_log_event::error_code
  
  A query can perform completely having the local var error of mysql_$query zero,
  where $query in insert, update, delete, load,
  and be  binlogged with error_code e.g KILLED_QUERY while there is no reason do to so.
  That can happen because Query_log_event consults thd->killed flag to evaluate
  error_code.
  
  Fixed with implementing a scheme suggested and partly implemented at time of bug@22725 work-on.
  error_status is cached immediatly after the control leaves the main rows-loop. The cached value
  is passed to Query_log_event constructor, not the default thd->killed which can be changed
  in between of the caching and the constructing.
  
  A simulation test is provided although it can not be easily made deterministic. So it has to be moved
  to the manual suite.
[16 Oct 2007 15: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/35665

ChangeSet@1.2542, 2007-10-16 18:02:13+03:00, aelkin@dsl-hkibras1-ff5fc300-23.dhcp.inet.fi +5 -0
  Bug #27571 asynchronousity in setting mysql_`query`::error and Query_log_event::error_code
  
  A query can perform completely having the local var error of mysql_$query zero,
  where $query in insert, update, delete, load,
  and be  binlogged with error_code e.g KILLED_QUERY while there is no reason do to so.
  That can happen because Query_log_event consults thd->killed flag to evaluate
  error_code.
  
  Fixed with implementing a scheme suggested and partly implemented at time of bug@22725 work-on.
  error_status is cached immediatly after the control leaves the main rows-loop. The cached value
  is passed to Query_log_event constructor, not the default thd->killed which can be changed
  in between of the caching and the constructing.
  
  A simulation test is provided although it can not be easily made deterministic. So it has to be moved
  to the manual suite.
  
  The current changeset is limited to capture only UPDATE query. The rest of modifying DMS:s will be handled
  by deploying the current pattern upon successful review of it.
[16 Oct 2007 16:57] 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/35691

ChangeSet@1.2542, 2007-10-16 19:19:57+03:00, aelkin@dsl-hkibras1-ff5fc300-23.dhcp.inet.fi +5 -0
  Bug #27571 asynchronousity in setting mysql_`query`::error and Query_log_event::error_code
  
  A query can perform completely having the local var error of mysql_$query zero,
  where $query in insert, update, delete, load,
  and be  binlogged with error_code e.g KILLED_QUERY while there is no reason do to so.
  That can happen because Query_log_event consults thd->killed flag to evaluate
  error_code.
  
  Fixed with implementing a scheme suggested and partly implemented at time of bug@22725 work-on.
  error_status is cached immediatly after the control leaves the main rows-loop and that instance
  always corresponds to `error' the local of mysql_$query functions. The cached value
  is passed to Query_log_event constructor, not the default thd->killed which can be changed
  in between of the caching and the constructing.
  
  A simulation test is provided although it can not be easily made deterministic. So it has to be moved
  to the manual suite.
  
  The current changeset is limited to capture only UPDATE query. The rest of modifying DMS:s will be handled
  by deploying the current pattern upon successful review of it.
[24 Oct 2007 6:31] 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/36223

ChangeSet@1.2542, 2007-10-24 09:31:23+03:00, aelkin@koti.dsl.inet.fi +10 -0
  Bug #27571 asynchronousity in setting mysql_`query`::error and Query_log_event::error_code
  
  A query can perform completely having the local var error of mysql_$query zero,
  where $query in insert, update, delete, load,
  and be  binlogged with error_code e.g KILLED_QUERY while there is no reason do to so.
  That can happen because Query_log_event consults thd->killed flag to evaluate
  error_code.
  
  Fixed with implementing a scheme suggested and partly implemented at time of bug@22725 work-on.
  error_status is cached immediatly after the control leaves the main rows-loop and that instance
  always corresponds to `error' the local of mysql_$query functions. The cached value
  is passed to Query_log_event constructor, not the default thd->killed which can be changed
  in between of the caching and the constructing.
  
  A simulation test is provided although it can not be easily made deterministic. So it has to be moved
  to the manual suite.
  
  The current changeset is limited to capture only UPDATE query. The rest of modifying DMS:s will be handled
  by deploying the current pattern upon successful review of it.
[29 Oct 2007 10:47] 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/36535

ChangeSet@1.2542, 2007-10-29 12:47:31+02:00, aelkin@koti.dsl.inet.fi +10 -0
  Bug #27571 asynchronousity in setting mysql_`query`::error and Query_log_event::error_code
  
  A query can perform completely having the local var error of mysql_$query zero,
  where $query in insert, update, delete, load,
  and be  binlogged with error_code e.g KILLED_QUERY while there is no reason do to so.
  That can happen because Query_log_event consults thd->killed flag to evaluate
  error_code.
  
  Fixed with implementing a scheme suggested and partly implemented at time of bug@22725 work-on.
  error_status is cached immediatly after the control leaves the main rows-loop and that instance
  always corresponds to `error' the local of mysql_$query functions. The cached value
  is passed to Query_log_event constructor, not the default thd->killed which can be changed
  in between of the caching and the constructing.
[29 Oct 2007 11:39] 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/36539

ChangeSet@1.2542, 2007-10-29 13:38:49+02:00, aelkin@koti.dsl.inet.fi +12 -0
  Bug #27571 asynchronousity in setting mysql_`query`::error and
             Query_log_event::error_code
  
  A query can perform completely having the local var error of mysql_$query
  zero, where $query in insert, update, delete, load,
  and be  binlogged with error_code e.g KILLED_QUERY while there is no
  reason do to so.
  That can happen because Query_log_event consults thd->killed flag to
  evaluate error_code.
  
  Fixed with implementing a scheme suggested and partly implemented at
  time of bug@22725 work-on. error_status is cached immediatly after the
  control leaves the main rows-loop and that instance always corresponds
  to `error' the local of mysql_$query functions. The cached value
  is passed to Query_log_event constructor, not the default thd->killed
  which can be changed in between of the caching and the constructing.
[29 Oct 2007 13:21] 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/36557

ChangeSet@1.2542, 2007-10-29 15:20:59+02:00, aelkin@koti.dsl.inet.fi +12 -0
  Bug #27571 asynchronousity in setting mysql_`query`::error and
             Query_log_event::error_code
  
  A query can perform completely having the local var error of mysql_$query
  zero, where $query in insert, update, delete, load,
  and be  binlogged with error_code e.g KILLED_QUERY while there is no
  reason do to so.
  That can happen because Query_log_event consults thd->killed flag to
  evaluate error_code.
  
  Fixed with implementing a scheme suggested and partly implemented at
  time of bug@22725 work-on. error_status is cached immediatly after the
  control leaves the main rows-loop and that instance always corresponds
  to `error' the local of mysql_$query functions. The cached value
  is passed to Query_log_event constructor, not the default thd->killed
  which can be changed in between of the caching and the constructing.
[31 Oct 2007 9:49] 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/36735

ChangeSet@1.2605, 2007-10-31 11:48:49+02:00, aelkin@koti.dsl.inet.fi +7 -0
  bug#27571 merging. Fixing offsets and moving tests to the corrent
  destination. Removing wrong (local temp) tests.
[5 Nov 2007 20:10] 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/37136

ChangeSet@1.2611, 2007-11-05 22:10:25+02:00, aelkin@koti.dsl.inet.fi +3 -0
  bug#27571 asynchronous setting mysql_`query`::error and Query_log_e::error_code
  
  refining tests as they appear to be non-deterministic.
[6 Nov 2007 9:53] 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/37166

ChangeSet@1.2612, 2007-11-06 11:53:47+02:00, aelkin@koti.dsl.inet.fi +2 -0
  bug#27571 
  
  non-deterministic tests execution on some platforms.
[6 Nov 2007 11:08] 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/37175

ChangeSet@1.2613, 2007-11-06 13:08:37+02:00, aelkin@koti.dsl.inet.fi +1 -0
  bug#27571
  
  non-deterministic tests refining.
  This particular patch tested on two archs.
[6 Nov 2007 11:53] 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/37176

ChangeSet@1.2549, 2007-11-06 13:53:26+02:00, aelkin@koti.dsl.inet.fi +3 -0
  bug#27571
  
  commit is specific for 5.0 to eliminated non-deterministic tests.
  Those tests run only in 5.1 env where there is a necessary devices such
  as processlist table of info_schema.
[6 Nov 2007 14:25] 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/37186

ChangeSet@1.2551, 2007-11-06 16:25:32+02:00, aelkin@koti.dsl.inet.fi +1 -0
  bug#27571
  
  fixing tests
[6 Nov 2007 18:10] 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/37205

ChangeSet@1.2617, 2007-11-06 20:09:45+02:00, aelkin@koti.dsl.inet.fi +1 -0
  bug#27571
  
  tests fixing: refreshing the results file.
[6 Nov 2007 18:31] 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/37207

ChangeSet@1.2552, 2007-11-06 20:31:40+02:00, aelkin@koti.dsl.inet.fi +2 -0
  bug#27571
  
  refining non-deterministic tests.
  The new Bug@32148 is in the way. Adjuting the tests to be somehow useful.
[27 Nov 2007 10:48] Bugs System
Pushed into 5.0.54
[27 Nov 2007 10:50] Bugs System
Pushed into 5.1.23-rc
[27 Nov 2007 10:52] Bugs System
Pushed into 6.0.4-alpha
[23 Jan 2008 18:48] Paul DuBois
Noted in 5.0.54, 5.1.23, 6.0.5 changelogs.

A race condition between killing a statement and the thread executing
the statement could lead to a situation such that the binary log
contained an event indicating that the statement was killed, whereas
the statement actually executed to completion.