Bug #22344 InnoDB keys act strange on datetime vs timestamp comparison
Submitted: 14 Sep 2006 13:08 Modified: 20 Feb 2007 20:11
Reporter: Christian Hammers (Silver Quality Contributor) (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S2 (Serious)
Version:5.0.26-BK, 5.0.24a OS:Linux (Linux)
Assigned to: Georgi Kodinov

[14 Sep 2006 13:08] Christian Hammers
Description:
Hello

The following query works on the tables below when using MyISAM but gives
a warning and NO result rows when using InnoDB as engine.

The Query:
   SELECT * 
   FROM history as h left join ports as p on (h.port_id=p.id) 
   WHERE 
     h.port_id=30 and 
     h.stamp between p.activation and p.deactivation and
     h.stamp between "2006-01-01" and "2006-12-31"\G
  Empty set, 1 warning (0.00 sec)

mysql> SHOW WARNINGS;
+---------+------+-----------------------------------------------------------------------------+
| Level   | Code | Message                                                                     |
+---------+------+-----------------------------------------------------------------------------+
| Warning | 1292 | Incorrect datetime value: '2999-12-31 00:00:00' for column 'stamp' at row 1 | 
+---------+------+-----------------------------------------------------------------------------+
1 row in set (0.00 sec)

How to repeat:
#
# The tables
#

CREATE TABLE history (
  port_id int(10) unsigned NOT NULL,
  stamp timestamp NOT NULL,
  KEY stamp (stamp)
) ENGINE=InnoDB;

INSERT INTO history VALUES (30, '2006-01-03 23:00:00');

CREATE TABLE ports (
  id int(10) unsigned NOT NULL,
  activation datetime NOT NULL,
  deactivation datetime NOT NULL,
  PRIMARY KEY  (id)
) ENGINE=InnoDB;

INSERT INTO ports VALUES (30, '2006-01-01 00:00:00', '2999-12-31 00:00:00');

#
# Tested conditions
#

It works after ONE of the followings:
  *  ALTER TABLE ports DROP PRIMARY KEY;
  *  ALTER TABLE history ENGINE=MyISAM;
  *  ALTER TABLE history DROP KEY (stamp);

# 
# Proof of the InnoDB vs MyISAM behaviour:
# 

mysql> ALTER TABLE history ENGINE=MyISAM;
Query OK, 1 row affected (0.01 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql>  select * FROM history as h left join ports as p on (h.port_id=p.id) WHERE h.port_id=30 and h.stamp between p.activation and p.deactivation  and h.stamp between "2006-01-01" and "2006-12-31"\G
*************************** 1. row ***************************
     port_id: 30
       stamp: 2006-01-04 00:00:00
          id: 30
  activation: 2006-01-01 00:00:00
deactivation: 2999-12-31 00:00:00
1 row in set (0.00 sec)

mysql> ALTER TABLE history ENGINE=InnoDB;
Query OK, 1 row affected (0.06 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql>  select * FROM history as h left join ports as p on (h.port_id=p.id) WHERE h.port_id=30 and h.stamp between p.activation and p.deactivation  and h.stamp between "2006-01-01" and "2006-12-31"\G
Empty set, 1 warning (0.00 sec)

#
# Proof of the history.stamp Key behaviour
#

mysql> ALTER TABLE history DROP KEY stamp;
Query OK, 1 row affected (0.06 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql>  select * FROM history as h left join ports as p on (h.port_id=p.id) WHERE h.port_id=30 and h.stamp between p.activation and p.deactivation  and h.stamp between "2006-01-01" and "2006-12-31"\G
*************************** 1. row ***************************
     port_id: 30
       stamp: 2006-01-04 00:00:00
          id: 30
  activation: 2006-01-01 00:00:00
deactivation: 2999-12-31 00:00:00
1 row in set (0.00 sec)

mysql> ALTER TABLE history ADD KEY (stamp);
Query OK, 1 row affected (0.02 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql>  select * FROM history as h left join ports as p on (h.port_id=p.id) WHERE h.port_id=30 and h.stamp between p.activation and p.deactivation  and h.stamp between "2006-01-01" and "2006-12-31"\G
Empty set, 1 warning (0.00 sec)

Suggested fix:
Don't know.
[14 Sep 2006 14:32] Valerii Kravchuk
Thank you for a bug report. Verified just as described with latest 5.0.26-BK on Linux:

openxs@suse:~/dbs/5.0> bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 5.0.26-debug

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> CREATE TABLE history (
    ->   port_id int(10) unsigned NOT NULL,
    ->   stamp timestamp NOT NULL,
    ->   KEY stamp (stamp)
    -> ) ENGINE=InnoDB;
Query OK, 0 rows affected (0.10 sec)

mysql> INSERT INTO history VALUES (30, '2006-01-03 23:00:00');
Query OK, 1 row affected (0.01 sec)

mysql> CREATE TABLE ports (
    ->   id int(10) unsigned NOT NULL,
    ->   activation datetime NOT NULL,
    ->   deactivation datetime NOT NULL,
    ->   PRIMARY KEY  (id)
    -> ) ENGINE=InnoDB;
Query OK, 0 rows affected (0.02 sec)

mysql> INSERT INTO ports VALUES (30, '2006-01-01 00:00:00', '2999-12-31 00:00:0
0');
Query OK, 1 row affected (0.01 sec)

mysql> SELECT *
    ->    FROM history as h left join ports as p on (h.port_id=p.id)
    ->    WHERE
    ->      h.port_id=30 and
    ->      h.stamp between p.activation and p.deactivation and
    ->      h.stamp between "2006-01-01" and "2006-12-31";
Empty set, 1 warning (0.00 sec)

mysql> show warnings\G
*************************** 1. row ***************************
  Level: Warning
   Code: 1292
Message: Incorrect datetime value: '2999-12-31 00:00:00' for column 'stamp' at r
ow 1
1 row in set (0.00 sec)

mysql> ALTER TABLE history ENGINE=MyISAM;
Query OK, 1 row affected (0.05 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> select * FROM history as h left join ports as p on (h.port_id=p.id)
    -> WHERE h.port_id=30 and h.stamp between p.activation and p.deactivation
and
    -> h.stamp between "2006-01-01" and "2006-12-31"\G
*************************** 1. row ***************************
     port_id: 30
       stamp: 2006-01-03 23:00:00
          id: 30
  activation: 2006-01-01 00:00:00
deactivation: 2999-12-31 00:00:00
1 row in set (0.01 sec)
[14 Nov 2006 16:40] Heikki Tuuri
Looks like MySQL never queries InnoDB's table history at all!
[15 Nov 2006 19:10] Heikki Tuuri
This is probably a bug in the MySQL interpreter.

I ran this inside gdb. MySQL queries for a row with id = 30 in table 'ports'.

InnoDB inserted into 'ports' the row:

(gdb) x/30b record
0x8a44698:      0xff    0x1e    0x00    0x00    0x00    0x40    0xbb    0x31
0x8a446a0:      0x9b    0x3e    0x12    0x00    0x00    0xc0    0x8d    0xab
0x8a446a8:      0xe0    0x46    0x1b    0x00    0x00    0xa5    0xa5    0xa5
0x8a446b0:      0x05    0x1e    0x00    0x00    0x00    0x40

and InnoDB returns the exact same row in the query. Note that the first byte is not relevant because columns are declared as NOT NULL in 'ports':

(gdb) x/30b buf
0x8a44698:      0x05    0x1e    0x00    0x00    0x00    0x40    0xbb    0x31
0x8a446a0:      0x9b    0x3e    0x12    0x00    0x00    0xc0    0x8d    0xab
0x8a446a8:      0xe0    0x46    0x1b    0x00    0x00    0xa5    0xa5    0xa5
0x8a446b0:      0x05    0x1e    0x00    0x00    0x00    0x40

After that, MySQL never queries InnoDB's 'history' table at all! The tables are of InnoDB type, and the row count correctly shows as 1:

mysql> show table status like 'ports';                                          +-------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-------------------+----------+----------------+-------------------+
| Name  | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time         | Update_time | Check_time | Collation         | Checksum | Create_options | Comment           |
+-------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-------------------+----------+----------------+-------------------+
| ports | InnoDB |      10 | Compact    |    1 |          16384 |       16384 |               0 |            0 |         0 |           NULL | 2006-11-15 20:22:11 | NULL        | NULL       | latin1_swedish_ci |     NULL |                | InnoDB free: 0 kB |
+-------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-------------------+----------+----------------+-------------------+
1 row in set (0.00 sec)

mysql> show table status like 'history';                                        +---------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-------------------+----------+----------------+-------------------+
| Name    | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time         | Update_time | Check_time | Collation         | Checksum | Create_options | Comment           |
+---------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-------------------+----------+----------------+-------------------+
| history | InnoDB |      10 | Compact    |    1 |          16384 |       16384 |               0 |        16384 |         0 |           NULL | 2006-11-14 18:34:48 | NULL        | NULL       | latin1_swedish_ci |     NULL |                | InnoDB free: 0 kB |
+---------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-------------------+----------+----------------+-------------------+
1 row in set (0.00 sec)
[15 Nov 2006 19:13] Heikki Tuuri
Here some gdb trace from the execution:

Breakpoint 3, ha_innobase::index_read_idx (this=0x8a44568,
    buf=0x8a44698 "\005\036", keynr=0, key=0x8a4a950 "\036", key_len=4,
    find_flag=HA_READ_KEY_EXACT) at ha_innodb.cc:3944
3944            if (change_active_index(keynr)) {
Current language:  auto; currently c++
(gdb) c
Continuing.

Breakpoint 1, build_template (prebuilt=0x42a21268, thd=0x8a26390,
    table=0x8a43d48, templ_type=1) at ha_innodb.cc:2897
2897            ulint           n_requested_fields      = 0;
(gdb) bt
#0  build_template (prebuilt=0x42a21268, thd=0x8a26390, table=0x8a43d48,
    templ_type=1) at ha_innodb.cc:2897
#1  0x083112fd in ha_innobase::change_active_index (this=0x8a44568, keynr=0)
    at ha_innodb.cc:3921
#2  0x08311346 in ha_innobase::index_read_idx (this=0x8a44568,
    buf=0x8a44698 "\005\036", keynr=0, key=0x8a4a950 "\036", key_len=4,
    find_flag=HA_READ_KEY_EXACT) at ha_innodb.cc:3944
#3  0x08284386 in join_read_const (tab=0x8a4a3a0) at sql_select.cc:10625
#4  0x08283f83 in join_read_const_table (tab=0x8a4a3a0, pos=0x8a44a10)
    at sql_select.cc:10528
#5  0x082725c3 in make_join_statistics (join=0x8a44998, tables=0x0,
    conds=0x8a4a000, keyuse_array=0x8a456b8) at sql_select.cc:2357
#6  0x0826d082 in JOIN::optimize (this=0x8a44998) at sql_select.cc:717
#7  0x08271336 in mysql_select (thd=0x8a26390, rref_pointer_array=0x8a2678c,
    tables=0x8a48bb0, wild_num=1, fields=@0x8a266f0, conds=0x8a49ac0,
    og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0,
    select_options=2156153344, result=0x8a49bd0, unit=0x8a26434,
    select_lex=0x8a26664) at sql_select.cc:2001
#8  0x0826bac2 in handle_select (thd=0x8a26390, lex=0x8a263d0,
    result=0x8a49bd0, setup_tables_done_option=0) at sql_select.cc:245
#9  0x0822e1d9 in mysql_execute_command (thd=0x8a26390) at sql_parse.cc:2587
#10 0x082375b0 in mysql_parse (thd=0x8a26390,
    inBuf=0x8a489c0 "SELECT *         FROM history as h left join ports as p on (h.port_id=p.id)         WHERE", ' ' <repeats 11 times>, "h.port_id=30 and", ' ' <repeats 11 times>, "h.stamp between p.activation and p.deactivation and", ' ' <repeats 11 times>, "h.stamp bet"..., length=234) at sql_parse.cc:5870
#11 0x0822c1d9 in dispatch_command (command=COM_QUERY, thd=0x8a26390,
    packet=0x8a3e1c9 "SELECT *         FROM history as h left join ports as p on (h.port_id=p.id)         WHERE", ' ' <repeats 11 times>, "h.port_id=30 and", ' ' <repeats 11 times>, "h.stamp between p.activation and p.deactivation and", ' ' <repeats 11 times>, "h.stamp bet"..., packet_length=235) at sql_parse.cc:1766
#12 0x0822b929 in do_command (thd=0x8a26390) at sql_parse.cc:1550
#13 0x0822aa12 in handle_one_connection (arg=0x8a26390) at sql_parse.cc:1181
#14 0x40041b63 in start_thread () from /lib/tls/libpthread.so.0
#15 0x4018718a in clone () from /lib/tls/libc.so.6
(gdb) c
Continuing.

Breakpoint 5, ha_innobase::index_read (this=0x8a44568,
    buf=0x8a44698 "\005\036", key_ptr=0x8a4a950 "\036", key_len=4,
    find_flag=HA_READ_KEY_EXACT) at ha_innodb.cc:3760
3760            row_prebuilt_t* prebuilt        = (row_prebuilt_t*) innobase_prebuilt;
(gdb) c
Continuing.

Breakpoint 1, build_template (prebuilt=0x42a21268, thd=0x8a26390,
    table=0x8a43d48, templ_type=1) at ha_innodb.cc:2897
2897            ulint           n_requested_fields      = 0;
(gdb) bt
#0  build_template (prebuilt=0x42a21268, thd=0x8a26390, table=0x8a43d48,
    templ_type=1) at ha_innodb.cc:2897
#1  0x08310f39 in ha_innobase::index_read (this=0x8a44568,
    buf=0x8a44698 "\005\036", key_ptr=0x8a4a950 "\036", key_len=4,
    find_flag=HA_READ_KEY_EXACT) at ha_innodb.cc:3788
#2  0x08311381 in ha_innobase::index_read_idx (this=0x8a44568,
    buf=0x8a44698 "\005\036", keynr=0, key=0x8a4a950 "\036", key_len=4,
    find_flag=HA_READ_KEY_EXACT) at ha_innodb.cc:3949
#3  0x08284386 in join_read_const (tab=0x8a4a3a0) at sql_select.cc:10625
#4  0x08283f83 in join_read_const_table (tab=0x8a4a3a0, pos=0x8a44a10)
    at sql_select.cc:10528
#5  0x082725c3 in make_join_statistics (join=0x8a44998, tables=0x0,
    conds=0x8a4a000, keyuse_array=0x8a456b8) at sql_select.cc:2357
#6  0x0826d082 in JOIN::optimize (this=0x8a44998) at sql_select.cc:717
#7  0x08271336 in mysql_select (thd=0x8a26390, rref_pointer_array=0x8a2678c,
    tables=0x8a48bb0, wild_num=1, fields=@0x8a266f0, conds=0x8a49ac0,
    og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0,
    select_options=2156153344, result=0x8a49bd0, unit=0x8a26434,
    select_lex=0x8a26664) at sql_select.cc:2001
#8  0x0826bac2 in handle_select (thd=0x8a26390, lex=0x8a263d0,
    result=0x8a49bd0, setup_tables_done_option=0) at sql_select.cc:245
#9  0x0822e1d9 in mysql_execute_command (thd=0x8a26390) at sql_parse.cc:2587
#10 0x082375b0 in mysql_parse (thd=0x8a26390,
    inBuf=0x8a489c0 "SELECT *         FROM history as h left join ports as p on (h.port_id=p.id)         WHERE", ' ' <repeats 11 times>, "h.port_id=30 and", ' ' <repeats 11 times>, "h.stamp between p.activation and p.deactivation and", ' ' <repeats 11 times>, "h.stamp bet"..., length=234) at sql_parse.cc:5870
#11 0x0822c1d9 in dispatch_command (command=COM_QUERY, thd=0x8a26390,
    packet=0x8a3e1c9 "SELECT *         FROM history as h left join ports as p on (h.port_id=p.id)         WHERE", ' ' <repeats 11 times>, "h.port_id=30 and", ' ' <repeats 11 times>, "h.stamp between p.activation and p.deactivation and", ' ' <repeats 11 times>, "h.stamp bet"..., packet_length=235) at sql_parse.cc:1766
#12 0x0822b929 in do_command (thd=0x8a26390) at sql_parse.cc:1550
#13 0x0822aa12 in handle_one_connection (arg=0x8a26390) at sql_parse.cc:1181
#14 0x40041b63 in start_thread () from /lib/tls/libpthread.so.0
#15 0x4018718a in clone () from /lib/tls/libc.so.6
(gdb) c
Continuing.

Breakpoint 2, row_search_for_mysql (buf=0x8a44698 "\005\036", mode=2,
    prebuilt=0x42a21268, match_mode=1, direction=0) at row0sel.c:3066
3066            dict_index_t*   index           = prebuilt->index;
Current language:  auto; currently c
(gdb)
Continuing.

Breakpoint 7, row_sel_store_mysql_rec (mysql_rec=0x42a1b7ec "\005\036",
    prebuilt=0x42a21268, rec=0x42c7807d "", offsets=0x495a6210)
    at row0sel.c:2422

...

(gdb)
4136            return(err);
(gdb)
4137    }
(gdb)
ha_innobase::index_read (this=0x8a44568, buf=0x8a44698 "\005\036",
    key_ptr=0x8a4a950 "\036", key_len=4, find_flag=HA_READ_KEY_EXACT)
    at ha_innodb.cc:3827
3827            innodb_srv_conc_exit_innodb(prebuilt->trx);
Current language:  auto; currently c++
(gdb)
3829            if (ret == DB_SUCCESS) {
(gdb)
3830                    error = 0;
(gdb)
3831                    table->status = 0;
(gdb)
3845            DBUG_RETURN(error);
(gdb) x/30b buf
0x8a44698:      0x05    0x1e    0x00    0x00    0x00    0x40    0xbb    0x31
0x8a446a0:      0x9b    0x3e    0x12    0x00    0x00    0xc0    0x8d    0xab
0x8a446a8:      0xe0    0x46    0x1b    0x00    0x00    0xa5    0xa5    0xa5
0x8a446b0:      0x05    0x1e    0x00    0x00    0x00    0x40
(gdb)
[15 Nov 2006 19:16] Heikki Tuuri
EXPLAIN for InnoDB tables:

mysql> explain SELECT *         FROM history as h left join ports as p on (h.port_id=p.id)         WHERE           h.port_id=30 and           h.stamp between p.activation and p.deactivation and           h.stamp between "2006-01-01" and "2006-12-31";
+----+-------------+-------+------+---------------+------+---------+------+------+-----------------------------------------------------+
| id | select_type | table | type | possible_keys | key  | key_len | ref  | rows | Extra                                               |
+----+-------------+-------+------+---------------+------+---------+------+------+-----------------------------------------------------+
|  1 | SIMPLE      | NULL  | NULL | NULL          | NULL | NULL    | NULL | NULL | Impossible WHERE noticed after reading const tables |
+----+-------------+-------+------+---------------+------+---------+------+------+-----------------------------------------------------+
1 row in set, 1 warning (5.49 sec)

mysql>

EXPLAIN for MyISAM type tables:

mysql> explain SELECT *         FROM history as h left join ports as p on (h.port_id=p.id)         WHERE           h.port_id=30 and           h.stamp between p.activation and p.deactivation and           h.stamp between "2006-01-01" and "2006-12-31";
+----+-------------+-------+--------+---------------+------+---------+------+------+-------+
| id | select_type | table | type   | possible_keys | key  | key_len | ref  | rows | Extra |
+----+-------------+-------+--------+---------------+------+---------+------+------+-------+
|  1 | SIMPLE      | h     | system | stamp         | NULL | NULL    | NULL |    1 |       |
|  1 | SIMPLE      | p     | system | PRIMARY       | NULL | NULL    | NULL |    1 |       |
+----+-------------+-------+--------+---------------+------+---------+------+------+-------+
2 rows in set (0.01 sec)

mysql>
[6 Feb 2007 9:11] 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/19366

ChangeSet@1.2402, 2007-02-06 11:08:57+02:00, gkodinov@macbook.gmz +5 -0
  Bug #22344: InnoDB keys act strange on datetime vs timestamp comparison
   Ignoring error codes from type conversion allows default (wrong) values to
   go unnoticed in the formation of index search conditions.
   Fixed by correctly checking for conversion errors.
[6 Feb 2007 9:51] Georgi Kodinov
The bug is reproducible using MyISAM as well. 
But we need to have more than 1 row in the tables to reproduce the bug.
[9 Feb 2007 9:05] 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/19608

ChangeSet@1.2403, 2007-02-09 11:05:23+02:00, gkodinov@macbook.gmz +1 -0
  Addendum to fix of bug #22344 : removed dead code.
[14 Feb 2007 10:38] Igor Babaev
The fix has been pushed into 5.0.36 and 5.1.16-beta.
[20 Feb 2007 20:11] Paul Dubois
Noted in 5.0.36, 5.1.16 changelogs.

Type conversion errors during formation of index search conditions
were not correctly checked, leading to incorrect query results.