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: | |
Category: | MySQL Server: Optimizer | Severity: | S2 (Serious) |
Version: | 5.0.26-BK, 5.0.24a | OS: | Linux (Linux) |
Assigned to: | Georgi Kodinov | CPU Architecture: | Any |
[14 Sep 2006 13:08]
Christian Hammers
[14 Sep 2006 14:32]
Valeriy 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.