MySQL Bugs: #58816: Extra temporary duplicate rows in result set when switching ICP off

Bug #58816	Extra temporary duplicate rows in result set when switching ICP off
Submitted:	8 Dec 2010 14:24	Modified:	20 Jan 2011 19:13
Reporter:	John Embretsen	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Optimizer	Severity:	S3 (Non-critical)
Version:	5.6.1-m5	OS:	Any
Assigned to:	Olav Sandstå	CPU Architecture:	Any
Tags:	index_condition_pushdown, optimizer_switch, wl5639

Description:
Using a server with the "index_condition_pushdown" (ICP) feature enabled by default. If first executing a query against an InnoDB table, then switching ICP off and repeating the query, one gets different results (some rows are included twice). 

If repeating the query a second time, still with ICP off, the result is back to normal.

In the following session, assume table t1 has 10 rows.

mysql> -- assuming index_condition_pushdown=on ;
mysql> SELECT pk, col_int FROM t1 WHERE pk <> 3;
+----+-----------+
| pk | col_int   |
+----+-----------+
|  1 | 530644992 |
|  2 |         7 |
|  4 |         3 |
|  5 |         1 |
|  6 |      NULL |
|  7 | -26673152 |
|  8 |         2 |
|  9 |      NULL |
| 10 |      NULL |
+----+-----------+
9 rows in set (0.01 sec)

mysql> SET SESSION optimizer_switch='index_condition_pushdown=off';
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT pk, col_int FROM t1 WHERE pk <> 3;
+----+-----------+
| pk | col_int   |
+----+-----------+
|  1 | 530644992 |
|  2 |         7 |
|  4 |         3 |
|  5 |         1 |
|  6 |      NULL |
|  7 | -26673152 |
|  8 |         2 |
|  9 |      NULL |
| 10 |      NULL |
|  4 |         3 |
|  5 |         1 |
|  6 |      NULL |
|  7 | -26673152 |
|  8 |         2 |
|  9 |      NULL |
| 10 |      NULL |
+----+-----------+
16 rows in set (0.00 sec)

mysql> SELECT pk, col_int FROM t1 WHERE pk <> 3;
+----+-----------+
| pk | col_int   |
+----+-----------+
|  1 | 530644992 |
|  2 |         7 |
|  4 |         3 |
|  5 |         1 |
|  6 |      NULL |
|  7 | -26673152 |
|  8 |         2 |
|  9 |      NULL |
| 10 |      NULL |
+----+-----------+
9 rows in set (0.00 sec)

Note that the first query, with ICP on, yields correct results, and that only the first of several subsequent queries with ICP off yields wrong results.

It may seem like the first ICP execution leaves some data in memory that is later (wrongly) used in the subsequent query when ICP is off. For example, if switching ICP off immediately and then executing the query, the correct results are returned. Not able to repeat the issue by switching ICP back on, then off again.

How to repeat:
Check that ICP is available and enabled by executing

SHOW VARIABLES LIKE 'optimizer_switch';

and looking for "index_condition_pushdown=on".

Then do:

CREATE TABLE t1 (
  col_int INT,
  pk INT NOT NULL,
  PRIMARY KEY (pk)
) ENGINE=InnoDB;

INSERT INTO t1 VALUES (530644992,1);
INSERT INTO t1 VALUES (7,2);
INSERT INTO t1 VALUES (NULL,3);
INSERT INTO t1 VALUES (3,4);
INSERT INTO t1 VALUES (1,5);
INSERT INTO t1 VALUES (NULL,6);
INSERT INTO t1 VALUES (-26673152,7);
INSERT INTO t1 VALUES (2,8);
INSERT INTO t1 VALUES (NULL,9);
INSERT INTO t1 VALUES (NULL,10);

SELECT pk, col_int FROM t1 WHERE pk <> 3;

SET SESSION optimizer_switch='index_condition_pushdown=off';

SELECT pk, col_int FROM t1 WHERE pk <> 3;

SELECT pk, col_int FROM t1 WHERE pk <> 3;

-- end of repro ;

EXPLAIN shows that ICP is used when "on", and not used when "off:

mysql> EXPLAIN SELECT pk, col_int FROM t1 WHERE pk <> 3;
+----+-------------+-------+-------+---------------+---------+---------+------+------+-----------------------+
| id | select_type | table | type  | possible_keys | key     | key_len | ref  | rows | Extra                 |
+----+-------------+-------+-------+---------------+---------+---------+------+------+-----------------------+
|  1 | SIMPLE      | t1    | range | PRIMARY       | PRIMARY | 4       | NULL |    9 | Using index condition |
+----+-------------+-------+-------+---------------+---------+---------+------+------+-----------------------+
1 row in set (0.00 sec)

mysql> SET SESSION optimizer_switch='index_condition_pushdown=off';
Query OK, 0 rows affected (0.00 sec)

mysql> EXPLAIN SELECT pk, col_int FROM t1 WHERE pk <> 3;
+----+-------------+-------+-------+---------------+---------+---------+------+------+-------------+
| id | select_type | table | type  | possible_keys | key     | key_len | ref  | rows | Extra       |
+----+-------------+-------+-------+---------------+---------+---------+------+------+-------------+
|  1 | SIMPLE      | t1    | range | PRIMARY       | PRIMARY | 4       | NULL |    9 | Using where |
+----+-------------+-------+-------+---------------+---------+---------+------+------+-------------+
1 row in set (0.00 sec)

This far I am unable to repeat this using the lastest version from mysql-trunk-bugfixing (revid georgi.kodinov@oracle.com-20101208125540-ylcsu9ca377x4eqr). I have tried both running the reproduction case as an MTR test and manually without seeing the extra rows in the result.

Sorry, Olav, it seems that the "How to repeat" instructions were not as reliable as I first thought. Try adding "ENGINE=InnoDB" to the CREATE TABLE statement and an EXPLAIN statement before and after switching ICP off.

An MTR test case which seems to reproduce it for my with the trunk-bugfixing revid you mentioned:

--source include/have_innodb.inc

DROP TABLE IF EXISTS t1;

CREATE TABLE t1 (
  col_int INT,
  pk INT NOT NULL,
  PRIMARY KEY (pk)
) ENGINE=InnoDB;

INSERT INTO t1 VALUES (530644992,1);
INSERT INTO t1 VALUES (7,2);
INSERT INTO t1 VALUES (NULL,3);
INSERT INTO t1 VALUES (3,4);
INSERT INTO t1 VALUES (1,5);
INSERT INTO t1 VALUES (NULL,6);
INSERT INTO t1 VALUES (-26673152,7);
INSERT INTO t1 VALUES (2,8);
INSERT INTO t1 VALUES (NULL,9);
INSERT INTO t1 VALUES (NULL,10);

SELECT pk, col_int FROM t1 WHERE pk <> 3;

EXPLAIN SELECT pk, col_int FROM t1 WHERE pk <> 3;

SET SESSION optimizer_switch='index_condition_pushdown=off';

EXPLAIN SELECT pk, col_int FROM t1 WHERE pk <> 3;

SELECT pk, col_int FROM t1 WHERE pk <> 3;
SELECT pk, col_int FROM t1 WHERE pk <> 3;

DROP TABLE t1;

Hi John, Thanks for the updated test case. With this I am able to reproduce the extra duplicate rows in the result set.

Reduced version of original test case:

--source include/have_innodb.inc

CREATE TABLE t1 (
  pk INT NOT NULL,
  c1 INT NOT NULL,
  PRIMARY KEY (pk)
) ENGINE=InnoDB;

INSERT INTO t1 VALUES (1,9);
INSERT INTO t1 VALUES (2,7);
INSERT INTO t1 VALUES (3,6);
INSERT INTO t1 VALUES (4,3);
INSERT INTO t1 VALUES (5,1);

EXPLAIN SELECT pk, c1 FROM t1 WHERE pk <> 3;

SET SESSION optimizer_switch='index_condition_pushdown=off';

SELECT pk, c1 FROM t1 WHERE pk <> 3;

DROP TABLE t1;

Explanation for how the wrong result is produced:

Statement 1: EXPLAIN SELECT pk, c1 FROM t1 WHERE pk <> 3;
=========================================================

This produces the following explain for the query:

id      select_type     table   type    possible_keys   key     key_len ref     rows    Extra
1       SIMPLE  t1      range   PRIMARY PRIMARY 4       NULL    4       Using index condition

When running the EXPLAIN the optimizer also initializes the handler
object for the table to use index condition pushdown (ICP) by calling
handler::idx_cond_push(). Among the things this method does is to
assign values for the following ICP related member variables:

   pushed_idx_cond = `test`.`t1`.`pk` <> 3;
   pushed_idx_cond_keyno = 0 ;  /* The primary key */
   in_range_check_pushed_down = true;

After this the handler/storage engine will be responsible for
evaluating both the pushed index condition on the primary key AND it
will also be responsible for doing the range check for the range query
(the last thing is the important in this bug). Thus, the server will
not evaluate the pushed index condition NOR the range check after an
index condition has been pushed down to the handler.

Since this is only an explain the query will not be executed and the
handler object will be "freed" when this statement ends (it will be
cached in the runtime system to be re-used later if another statement
needs a handler object for this table).

Statement 2: SET SESSION optimizer_switch='index_condition_pushdown=off';
=========================================================================

Does what is says: after this ICP will not be used for this session.

Statement 3: SELECT pk, c1 FROM t1 WHERE pk <> 3;
=================================================

This query will be executed as a range scan on the primary key. The
multi-range interface will be used for retrieving the data using two
ranges:

  range 1: [-, 3>  (all records with primary key less than 3)
  range 2: <3, -]  (all records with primary key greater than 3)

For retrieving data from the table a handler object is needed and the
same handler object as used for the explain statement is re-used. When
retrieving data from range 1 above *all* records in the table is
returned from the handler (which is wrong, it should have stopped when
it reached the record with primary key equal to 3). Then the server
reads data from the second range which returns all records with key
larger than 3 (which is correct). So the "duplicate entries" in the
result set is caused by the reading of the first range to "fail" to
detect that it has reached the "end of range" criteria (and continues
to "end of table" instead").

So what causes this to happen? First, there are two main places where
we check if we have reached the end of a range:

a. The handler will check end range here: 

     handler::read_range_next() will call handler::compare_key()

   to validate that record is within the range. Note that this will
   always return "true" if "ICP" has been initialized for use (it
   checks the value of the in_range_check_pushed_down):

     if (!range || in_range_check_pushed_down)
        return 0;

b. If ICP is in use the ICP implementation (in InnoDB/MyISAM) will in
   addition call

     handler::compare_key2()

   to validate if the record is within the range.

So what is special about this situation? The cause for this to fail is
that when executing the explain statement the index condition was
pushed causing the "in_range_check_pushed_down" member to be set to
true. This is not reset back to false so when the handler object is
re-used for executing the query it still have the value true. So the
following happens with the above two tests that should detect if we
reach end of range:

a. The compare_key() called from handler::read_range_next() will
   always return OK since the in_range_check_pushed_down is true (see
   code above) (which is wrong).

b. The compare_key2() is never called by InnoDB since no index
   condition is pushed for this query (which is correct).

So the bug is: "handler::in_range_check_pushed_down" is not reset to
false when re-using a handler object that has previously been used for
an explain statement.

Some "bonus" information:
=========================

a. Why does this only happens when the original query is an explain query? 

   Because for a real query we will (at least normally) retrieve data
   using the index that we have pushed the index condition on. We will
   open and close a index scan on this index. When closing the index
   scan ha_innobase::index_end() will be called and this sets
   in_range_check_pushed_down back to false. (this is also the reason
   for this problem to be "temporary" and goes away after the first
   execution of the query).

b. Why did InnoDB not use ICP when executing the query (which would be
   a wrong thing to do but would have produced the correct result in
   this case)? (or rather why did only the
   "in_range_check_pushed_down" variable have a wrong value while the
   pushed_idx_cond and pushed_idx_cond_keyno had been reset to not use
   ICP?). The reason is that InnoDB does reset the last two when the
   lock on the handler object is released and a call to
   ha_innobase::reset_template() is done. If
   in_range_check_pushed_down also had been reset in
   ha_innobase::reset_template() we would not have had this problem.
   (Note: I do not necessarily think this is the right place to fix
   this problem).

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/128092

3461 Olav Sandstaa	2011-01-06
      Fix for Bug#58816 Extra temporary duplicate rows in result set when 
                        switching ICP off.
      
      The wrong result was caused by that the handler object was in an
      inconsistent state when running the query. The same handler object
      was previously used by an explain for the same query. 
      
      When doing the explain the optimizer pushed down an index condition to
      the handler. This set information about the pushed index condition
      as well as setting the member variable in_range_check_pushed_down to
      true. The inconsistency that this resulted in was that when the
      explain statement completed and the handler object was ready for
      re-use the information about the pushed index condition was reset but
      the in_range_check_pushed_down was still true.
      
      When executing the same query (after disabling index condition
      pushdown) using the same handler object with the
      in_range_check_pushed_down still being true caused that neither the
      server nor the storage engine were performing the range check. This
      resulted in that we would read to the end of the table for the first
      range instead of stopping at the end of range criterion.
      
      The fix for this problem is to add code to handler::ha_reset() to
      to reset both information about the pushed index condition and the
      in_range_check_pushed_down. This method is called when a
      statement closes its tables and the handler object is made ready
      for reuse.
     @ mysql-test/include/icp_tests.inc
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp_all.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp_none.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp_all.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp_none.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ sql/handler.cc
        When an explain is run on a statement using index condition pushdown
        it will leave the handler object in an inconsistent state where
        the information about the pushed index condition is reset while
        the value of in_range_check_pushed_down is still true. If this
        handler object is later re-used for a range query it might lead
        to more records being found due to the range condition is not
        evaluated neither by the server nor the storage engine.
        
        The fix for this is to extend handler::ha_reset() to reset
        both the information about pushed index condition and the
        in_range_check_pushed_down.

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/128418

3485 Olav Sandstaa	2011-01-11
      Fix for Bug#58816 Extra temporary duplicate rows in result set when 
                        switching ICP off.
      
      The wrong result was caused by that the handler object was in an
      inconsistent state when running the query. The same handler object
      was previously used by an explain for the same query. 
      
      When doing the explain the optimizer pushed down an index condition to
      the handler. This set information about the pushed index condition
      as well as setting the member variable in_range_check_pushed_down to
      true. The inconsistency that this resulted in was that when the
      explain statement completed and the handler object was ready for
      re-use the information about the pushed index condition was reset but
      the in_range_check_pushed_down was still true.
      
      When executing the same query (after disabling index condition
      pushdown) using the same handler object with the
      in_range_check_pushed_down still being true caused that neither the
      server nor the storage engine were performing the range check. This
      resulted in that we would read to the end of the table for the first
      range instead of stopping at the end of range criterion.
      
      The fix for this problem is to add code to handler::ha_reset() to
      to reset both information about the pushed index condition and the
      in_range_check_pushed_down. This method is called when a
      statement closes its tables and the handler object is made ready
      for reuse.
     @ mysql-test/include/icp_tests.inc
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp_all.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp_none.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp_all.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp_none.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ sql/handler.cc
        When an explain is run on a statement using index condition pushdown
        it will leave the handler object in an inconsistent state where
        the information about the pushed index condition is reset while
        the value of in_range_check_pushed_down is still true. If this
        handler object is later re-used for a range query it might lead
        to more records being found due to the range condition is not
        evaluated neither by the server nor the storage engine.
        
        The fix for this is to extend handler::ha_reset() to reset
        both the information about pushed index condition and the
        in_range_check_pushed_down.
     @ storage/innobase/handler/ha_innodb.cc
        Move resetting of the handler's ICP member variables to handler::ha_reset().
     @ storage/myisam/ha_myisam.cc
        Move resetting of the handler's ICP member variables to handler::ha_reset().

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/128582

3493 Olav Sandstaa	2011-01-13
      Fix for Bug#58816 Extra temporary duplicate rows in result set when 
                        switching ICP off.
      
      The wrong result was caused by that the handler object was in an
      inconsistent state when running the query. The same handler object
      was previously used by an explain for the same query. 
      
      When doing the explain the optimizer pushed down an index condition to
      the handler. This set information about the pushed index condition
      as well as setting the member variable in_range_check_pushed_down to
      true. The inconsistency that this resulted in was that when the
      explain statement completed and the handler object was ready for
      re-use the information about the pushed index condition was reset but
      the in_range_check_pushed_down was still true.
      
      When executing the same query (after disabling index condition
      pushdown) using the same handler object with the
      in_range_check_pushed_down still being true caused that neither the
      server nor the storage engine were performing the range check. This
      resulted in that we would read to the end of the table for the first
      range instead of stopping at the end of range criterion.
      
      The fix for this problem is to add code to handler::ha_reset() to
      to reset both information about the pushed index condition and the
      in_range_check_pushed_down. This method is called when a
      statement closes its tables and the handler object is made ready
      for reuse.
     @ mysql-test/include/icp_tests.inc
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp_all.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/innodb_icp_none.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp_all.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ mysql-test/r/myisam_icp_none.result
        Test case for Bug#58816 Extra temporary duplicate rows in result
        set when switching ICP off.
     @ sql/handler.cc
        When an explain is run on a statement using index condition pushdown
        it will leave the handler object in an inconsistent state where
        the information about the pushed index condition is reset while
        the value of in_range_check_pushed_down is still true. If this
        handler object is later re-used for a range query it might lead
        to more records being found due to the range condition is not
        evaluated neither by the server nor the storage engine.
        
        The fix for this is to extend handler::ha_reset() to reset
        both the information about pushed index condition and the
        in_range_check_pushed_down.
     @ storage/innobase/handler/ha_innodb.cc
        Move resetting of the handler's ICP member variables to handler::ha_reset().
     @ storage/myisam/ha_myisam.cc
        Move resetting of the handler's ICP member variables to handler::ha_reset().

Pushed into mysql-trunk 5.6.2 (revid:olav.sandstaa@oracle.com-20110113073303-xtc6rhbo1g9iaiqm) (version source revid:olav.sandstaa@oracle.com-20110113073303-xtc6rhbo1g9iaiqm) (merge vers: 5.6.2) (pib:24)

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/129286

3538 Olav Sandstaa	2011-01-20
      Follow-up patch for test case for Bug #58816. 
      
      The test case turns off index condition pushdown as part of the test
      but does not restore it to the value it had before the test case. This
      makes all test cases following it run with index condition pushdown
      turned off. The fix is to save the value of optimzier_switch before the
      test starts and restore it after the test.
     @ mysql-test/include/icp_tests.inc
        Save the value of the optimizer switch before the test case
        for Bug#58816 and restore it after.
     @ mysql-test/r/innodb_icp.result
        Save the value of the optimizer switch before the test case
        for Bug#58816 and restore it after.
     @ mysql-test/r/innodb_icp_none.result
        Save the value of the optimizer switch before the test case
        for Bug#58816 and restore it after.
     @ mysql-test/r/myisam_icp.result
        Save the value of the optimizer switch before the test case
        for Bug#58816 and restore it after.
     @ mysql-test/r/myisam_icp_none.result
        Save the value of the optimizer switch before the test case
        for Bug#58816 and restore it after.

Pushed into mysql-trunk 5.6.2 (revid:olav.sandstaa@oracle.com-20110120145703-1r29my2q0oux817s) (version source revid:olav.sandstaa@oracle.com-20110120145703-1r29my2q0oux817s) (merge vers: 5.6.2) (pib:24)

Noted in 5.6.2 changelog.

Running a query against an InnoDB table twice, first with index
condition pushdown enabled and then with it disabled, could produce
different results.