Bug #58837 | ICP crash or valgrind error due to uninitialized value in innobase_index_cond | ||
---|---|---|---|
Submitted: | 9 Dec 2010 10:39 | Modified: | 10 Jan 2011 16:46 |
Reporter: | Shane Bester (Platinum Quality Contributor) | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: Optimizer | Severity: | S1 (Critical) |
Version: | 5.6.1 | OS: | Any |
Assigned to: | Jørgen Løland | CPU Architecture: | Any |
Tags: | index_condition_pushdown, optimizer_switch |
[9 Dec 2010 10:39]
Shane Bester
[10 Dec 2010 11:03]
Valeriy Kravchuk
I've got valgrind error on -debug build of recent mysql-trunk-bugfixing tree on 32-bit Ubuntu 10.04: ==29615== Thread 17: ==29615== Conditional jump or move depends on uninitialised value(s) ==29615== at 0x8592794: innobase_index_cond (ha_innodb.cc:12338) ==29615== by 0x85B512C: row_search_idx_cond_check (row0sel.c:3447) ==29615== by 0x85B6F2A: row_search_for_mysql (row0sel.c:4492) ==29615== by 0x8588ADE: ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function) (ha_innodb.cc:6078) ==29615== by 0x858946F: ha_innobase::index_first(unsigned char*) (ha_innodb.cc:6380) ==29615== by 0x8589660: ha_innobase::rnd_next(unsigned char*) (ha_innodb.cc:6477) ==29615== by 0x837A422: handler::ha_rnd_next(unsigned char*) (handler.cc:2221) ==29615== by 0x8409821: subselect_uniquesubquery_engine::scan_table() (item_subselect.cc:2455) ==29615== by 0x8409AC3: subselect_uniquesubquery_engine::exec() (item_subselect.cc:2627) ==29615== by 0x84036DB: Item_subselect::exec() (item_subselect.cc:311) ==29615== by 0x8403A74: Item_in_subselect::exec() (item_subselect.cc:427) ==29615== by 0x8403704: Item_subselect::exec() (item_subselect.cc:316) ==29615==
[16 Dec 2010 12:06]
Marko Mäkelä
I can repeat this bug. I believe that the cause of this bug is outside InnoDB. Valgrind believes that h->end_range is not fully initialized here. The field handler::end_range should be initialized (to NULL) by ha_index_init() and ha_index_end(), among other places. The only place where InnoDB refers to ha_innobase::end_range is in innobase_index_cond(). In gdb, h->end_range reads NULL. According to the function disassembly, the Valgrind warning is issued for the h->end_range!=NULL check, before the compare_key2 call. 0x083f1712 in innobase_index_cond (file=0x7e9d430) at mysql-5.6/storage/innobase/handler/ha_innodb.cc:12583 12583 if (h->end_range && h->compare_key2(h->end_range) > 0) { (gdb) bt #0 0x083f1712 in innobase_index_cond (file=0x7e9d430) at mysql-5.6/storage/innobase/handler/ha_innodb.cc:12583 #1 0x08417bde in row_search_idx_cond_check (mysql_rec=<value optimized out>, prebuilt=0x7cb8e18, rec=<value optimized out>, offsets=0x7fb6ab8) at mysql-5.6/storage/innobase/row/row0sel.c:3456 #2 0x0841ae5a in row_search_for_mysql (buf=0x7e9d5f0 "\377", mode=1, prebuilt=0x7cb8e18, match_mode=0, direction=0) at mysql-5.6/storage/innobase/row/row0sel.c:4501 #3 0x083f5786 in ha_innobase::index_read (this=0x7e9d430, buf=0x7e9d5f0 "\377", key_ptr=0x0, key_len=0, find_flag=HA_READ_AFTER_KEY) at mysql-5.6/storage/innobase/handler/ha_innodb.cc:6113 #4 0x083f2964 in ha_innobase::index_first (this=0x7e9d430, buf=0x7e9d5f0 "\377") at mysql-5.6/storage/innobase/handler/ha_innodb.cc:6415 #5 0x083f68b8 in ha_innobase::rnd_next (this=0x7e9d430, buf=0x7e9d5f0 "\377") at mysql-5.6/storage/innobase/handler/ha_innodb.cc:6512 #6 0x08293f82 in handler::ha_rnd_next (this=0x7e9d430, buf=0x7e9d5f0 "\377") at mysql-5.6/sql/handler.cc:2221 #7 0x0830141e in subselect_uniquesubquery_engine::scan_table (this=0x7ea3f58) at mysql-5.6/sql/item_subselect.cc:2455 #8 0x082ffc93 in Item_subselect::exec (this=0x7ea0370) at mysql-5.6/sql/item_subselect.cc:311 #9 0x083003b0 in Item_in_subselect::val_bool (this=0x7ea0370) at mysql-5.6/sql/item_subselect.cc:1023 #10 0x082b099e in Item_in_optimizer::val_int (this=0x7ea1548) at mysql-5.6/sql/item_cmpfunc.cc:1932 #11 0x0829a0b0 in Item::val_bool (this=0x7ea1548) at mysql-5.6/sql/item.cc:200 #12 0x082afd27 in Item_func_not::val_int (this=0x7ea0460) at mysql-5.6/sql/item_cmpfunc.cc:289 #13 0x0829a0b0 in Item::val_bool (this=0x7ea0460) at mysql-5.6/sql/item.cc:200 #14 0x082b1f79 in Item_cond_and::val_int (this=0x7ea2d38) at mysql-5.6/sql/item_cmpfunc.cc:4641 #15 0x081c0e50 in evaluate_join_record (join=0x7ea0e88, join_tab=0x7ea2ad4, error=<value optimized out>) at mysql-5.6/sql/sql_select.cc:17496 #16 0x081c10a9 in sub_select (join=0x7ea0e88, join_tab=0x7ea2ad4, end_of_records=false) at mysql-5.6/sql/sql_select.cc:17328 #17 0x081c46d8 in do_select (join=0x7ea0e88, fields=<value optimized out>, table=0x0, procedure=0x0) at mysql-5.6/sql/sql_select.cc:16859 #18 0x081da965 in JOIN::exec (this=0x7ea0e88) at mysql-5.6/sql/sql_select.cc:3293 #19 0x08301d6b in subselect_single_select_engine::exec (this=0x7ea0880) at mysql-5.6/sql/item_subselect.cc:2392 #20 0x082ffc93 in Item_subselect::exec (this=0x7ea07e0) at mysql-5.6/sql/item_subselect.cc:311 #21 0x08300275 in Item_exists_subselect::val_bool (this=0x7ea07e0) at mysql-5.6/sql/item_subselect.cc:946 #22 0x082afd27 in Item_func_not::val_int (this=0x7ea08a8) at mysql-5.6/sql/item_cmpfunc.cc:289 #23 0x082d2b31 in eval_const_cond (cond=0x7ea08a8) at mysql-5.6/sql/item_func.cc:78 #24 0x081bf929 in internal_remove_eq_conds (thd=<value optimized out>, cond=0x7ea08a8, cond_value=<value optimized out>) at mysql-5.6/sql/sql_select.cc:14515 #25 0x081bf736 in internal_remove_eq_conds (thd=<value optimized out>, cond=0x7ea0928, cond_value=<value optimized out>) at mysql-5.6/sql/sql_select.cc:14421 #26 0x081bfb01 in remove_eq_conds (thd=0x7e22610, cond=0x7ea0928, cond_value=0x7e23b2c) at mysql-5.6/sql/sql_select.cc:14608 #27 0x081cdc0d in optimize_cond (join=<value optimized out>, conds=0x7ea0928, join_list=<value optimized out>, build_equalities=true, cond_value=0x7e23b2c) at mysql-5.6/sql/sql_select.cc:14380 #28 0x081d3394 in JOIN::optimize (this=0x7ea0a60) at mysql-5.6/sql/sql_select.cc:1822 #29 0x081dbfbb in mysql_select (thd=0x7e22610, rref_pointer_array=0x7e23bc4, tables=0x7e28a78, wild_num=0, fields=..., conds=0x7ea0928, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7ea0a50, unit=0x7e23674, select_lex=0x7e23ac0) at mysql-5.6/sql/sql_select.cc:3494 #30 0x081dca97 in handle_select (thd=0x7e22610, lex=0x7e23610, result=0x7ea0a50, setup_tables_done_option=0) at mysql-5.6/sql/sql_select.cc:323 #31 0x0819a5ef in execute_sqlcom_select (thd=0x7e22610, all_tables=<value optimized out>) at mysql-5.6/sql/sql_parse.cc:4493 #32 0x0819da8f in mysql_execute_command (thd=0x7e22610) at mysql-5.6/sql/sql_parse.cc:2089 #33 0x081a1c34 in mysql_parse (thd=0x7e22610, rawbuf=0x7e286d0 "select t60_1.col3019 from t60 as t60_1 \nwhere t60_1.col3019>=1 and not exists\n(select t60_1.col3023 from t60 as t60_1 \n where t60_1.col3013 not in\n (select t133_2.a133 from t133 as t133_2 \n where t6"...,
[16 Dec 2010 18:47]
John Embretsen
Just wanted to add that this bug is also seen in the form of sporadic crashes (segfaults) during Random Query Generator testing of the optimizer. First part of stacktrace from bug repro on segfault (non-valgrind): ---- called from signal handler with signal 11 (SIGSEGV) ------ [8] handler::compare_key2(this = 0x50f9860, range = 0x280), line 5425 in "handler.cc" [9] innobase_index_cond(file = 0x50f9860), line 12338 in "ha_innodb.cc" [10] row_search_idx_cond_check(mysql_rec = 0x50f9b20 "ÿ", prebuilt = 0x50f7fb8, rec = 0xfffffd7ffdc9007e "\x80", offsets = 0xfffffd7ffea89d68), line 3447 in "row0sel.c" [11] row_search_for_mysql(buf = 0x50f9b20 "ÿ", mode = 1U, prebuilt = 0x50f7fb8, match_mode = 0, direction = 0), line 4492 in "row0sel.c" [12] ha_innobase::index_read(this = 0x50f9860, buf = 0x50f9b20 "ÿ", key_ptr = (nil), key_len = 0, find_flag = HA_READ_AFTER_KEY), line 6077 in "ha_innodb. cc" [13] ha_innobase::index_first(this = 0x50f9860, buf = 0x50f9b20 "ÿ"), line 6380 in "ha_innodb.cc" [14] ha_innobase::rnd_next(this = 0x50f9860, buf = 0x50f9b20 "ÿ"), line 6477 in "ha_innodb.cc" [15] handler::ha_rnd_next(this = 0x50f9860, buf = 0x50f9b20 "ÿ"), line 2221 in "handler.cc" [16] subselect_uniquesubquery_engine::scan_table(this = 0x50ceed0), line 2443 in "item_subselect.cc" (...)
[20 Dec 2010 13:15]
Jørgen Løland
Simplified test case: create table t1 ( t1_int int, t1_time time ) engine=innodb; create table t2 ( t2_int int primary key, t2_int2 int ) engine=innodb; insert into t2 values (); insert into t1 values (); explain select * from t1 as t1a where not exists (select * from t1 as t1b where t1b.t1_int not in (select t2.t2_int from t2 where t1b.t1_time like t1b.t1_int or t1b.t1_time <> t2.t2_int2 and 6=7 ) ) ; id select_type table type possible_keys key key_len ref rows Extra 1 PRIMARY NULL NULL NULL NULL NULL NULL NULL Impossible WHERE 2 SUBQUERY t1b ALL NULL NULL NULL NULL 1 Using where 3 DEPENDENT SUBQUERY t2 unique_subquery PRIMARY PRIMARY 4 func 1 Using where; Full scan on NULL key
[20 Dec 2010 13:29]
Jørgen Løland
The test above gives this valgrind warning: ==27457== Conditional jump or move depends on uninitialised value(s) ==27457== at 0x9F5A7B: innobase_index_cond (ha_innodb.cc:12342) ==27457== by 0xA193B4: row_search_idx_cond_check (row0sel.c:3447) ==27457== by 0xA1B378: row_search_for_mysql (row0sel.c:4492) ==27457== by 0x9EBA0D: ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function) (ha_innodb.cc:6078) ==27457== by 0x9EC3E5: ha_innobase::index_first(unsigned char*) (ha_innodb.cc:6380) ==27457== by 0x9EC5DE: ha_innobase::rnd_next(unsigned char*) (ha_innodb.cc:6477) ==27457== by 0x76FA09: handler::ha_rnd_next(unsigned char*) (handler.cc:2221) ==27457== by 0x80368A: subselect_uniquesubquery_engine::scan_table() (item_subselect.cc:2443) which is the same as Marko reported above. As can be seen, we read the innodb primary index through the handler rnd functions. Setting end_range= NULL in ha_rnd_init() and ha_rnd_end() removes the valgrind warning, but I have another suspect for this bug: -------------------- Breakpoint 2, innobase_index_cond (file=0x19f98b0) at /home/jl208045/mysql/mysql-next-mr-opt-backporting-review1/storage/innobase/handler/ha_innodb.cc:12331 12331 DBUG_ENTER("innobase_index_cond"); (gdb) n 12333 ha_innobase* h = reinterpret_cast<class ha_innobase*>(file); 12335 DBUG_ASSERT(h->pushed_idx_cond); (gdb) p h->table->alias $1 = 0x19cf430 "t2" (gdb) p print_where(h->pushed_idx_cond, "ICP_on_t2", QT_ORDINARY) WHERE:(ICP_on_t2) 0x1a2c9f0 (`test`.`t1b`.`t1_time` like `test`.`t1b`.`t1_int`) ------------------- Thus, the ICP attached to t2 is about columns in t1. push_index_cond() in sql_select.cc confirms that we do push this condition to t2: T@4 : | | | | | | | | | | | | | | | | | >push_index_cond T@4 : | | | | | | | | | | | | | | | | | | info: table t2, other_tbls_ok 1 WHERE:(full cond) 0x247bfa8 ((`test`.`t1b`.`t1_time` like `test`.`t1b`.`t1_int`) and trigcond((<cache>(`test`.`t1b`.`t1_int`) = `test`.`t2`.`t2_int`))) WHERE:(idx cond) 0x24759e0 (`test`.`t1b`.`t1_time` like `test`.`t1b`.`t1_int`) T@4 : | | | | | | | | | | | | | | | | | | >ha_innobase::idx_cond_push T@4 : | | | | | | | | | | | | | | | | | | <ha_innobase::idx_cond_push WHERE:(icp cond) 0x24759e0 (`test`.`t1b`.`t1_time` like `test`.`t1b`.`t1_int`) ------------------------ If t2 did not have ICP (`test`.`t1b`.`t1_time` like `test`.`t1b`.`t1_int`) attached, innobase_index_cond() would not have been called in the first place because row_search_idx_cond_check() would return here: if (!prebuilt->idx_cond) { return(ICP_MATCH); }
[4 Jan 2011 12:31]
Olav Sandstå
In this case it seems like it is safe to include fields from the t1b table in the condition pushed down as index condition to t2. Before starting to read data from t2 we will already have read a record from t1b. So the record buffer which the pushed index condition will use for evaluation should contain a valid t1b record.
[5 Jan 2011 9:37]
Jørgen Løland
Olav, thanks for commenting. I will push a fix for the uninitialized end_range soon.
[5 Jan 2011 10:16]
Jørgen Løland
Compiled on amd64, valgrind reports another warning for this test case: ==31652== Conditional jump or move depends on uninitialised value(s) ==31652== at 0xA4B91E: rw_lock_set_writer_id_and_recursion_flag (sync0rw.ic:283) ==31652== by 0xA4C5F7: rw_lock_x_lock_low (sync0rw.c:569) ==31652== by 0xA4C718: rw_lock_x_lock_func (sync0rw.c:628) ==31652== by 0xB178D7: pfs_rw_lock_x_lock_func (sync0rw.ic:692) ==31652== by 0xB185F3: hash_lock_x_all (hash0hash.c:232) ==31652== by 0xAB72CF: buf_pool_validate_instance (buf0buf.c:4632) ==31652== by 0xAB7B97: buf_validate (buf0buf.c:4850) ==31652== by 0xAB2F12: buf_page_get_gen (buf0buf.c:2999) ==31652== by 0xA670BA: trx_rsegf_get_new (trx0rseg.ic:69) ==31652== by 0xA679A2: trx_rseg_mem_create (trx0rseg.c:195) ==31652== by 0xA67D04: trx_rseg_create_instance (trx0rseg.c:275) ==31652== by 0xA67F45: trx_rseg_list_and_array_init (trx0rseg.c:340) ==31652== by 0xA6B06E: trx_sys_init_at_db_start (trx0sys.c:962) ==31652== by 0xA490C5: innobase_start_or_create_for_mysql (srv0start.c:1714) ==31652== by 0x9E9E53: innobase_init(void*) (ha_innodb.cc:2674) ==31652== by 0x76D7AC: ha_initialize_handlerton(st_plugin_int*)(handler.cc:475) I think this is another bug unrelated to ICP.
[5 Jan 2011 10:31]
Jørgen Løland
Test case will fail due to BUG#59307. Test will be added by implementor of that bugfix.
[5 Jan 2011 11:40]
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/127961 3475 Jorgen Loland 2011-01-05 BUG#58837: ICP crash or valgrind error due to uninitialized value in innobase_index_cond The problem was that ICP pushed a condition to an InnoDB table accessed through the primary key, and handler::end_range was not initialized in this case. This problem emerged now because ICP on InnoDB primary index has recently been enabled. Test case will be added by bug 59307 @ sql/handler.h Initialize handler::end_range in ha_rnd_init() and ha_rnd_end()
[7 Jan 2011 14:06]
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/128172 3475 Jorgen Loland 2011-01-07 BUG#58837: ICP crash or valgrind error due to uninitialized value in innobase_index_cond The problem was that ICP pushed a condition to an InnoDB table accessed through the primary key, and handler::end_range was not initialized in this case. This problem emerged now because ICP on InnoDB primary index has recently been enabled. @ mysql-test/include/icp_tests.inc Added test case for BUG#58837 @ mysql-test/r/innodb_icp.result Added test case for BUG#58837 @ mysql-test/r/innodb_icp_none.result Added test case for BUG#58837 @ mysql-test/r/myisam_icp.result Added test case for BUG#58837 @ mysql-test/r/myisam_icp_none.result Added test case for BUG#58837 @ sql/handler.h Initialize handler::end_range in ha_rnd_init() and ha_rnd_end()
[10 Jan 2011 9:04]
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/128254 3471 Jorgen Loland 2011-01-10 BUG#58837: ICP crash or valgrind error due to uninitialized value in innobase_index_cond The problem was that ICP pushed a condition to an InnoDB table accessed through the primary key, and handler::end_range was not initialized in this case. This problem emerged now because ICP on InnoDB primary index has recently been enabled. @ mysql-test/include/icp_tests.inc Added test case for BUG#58837 @ mysql-test/r/innodb_icp.result Added test case for BUG#58837 @ mysql-test/r/innodb_icp_none.result Added test case for BUG#58837 @ mysql-test/r/myisam_icp.result Added test case for BUG#58837 @ mysql-test/r/myisam_icp_none.result Added test case for BUG#58837 @ sql/handler.h Initialize handler::end_range in ha_rnd_init() and ha_rnd_end()
[10 Jan 2011 9:05]
Bugs System
Pushed into mysql-trunk 5.6.2 (revid:jorgen.loland@oracle.com-20110110090420-iep4ek5s7klq6rwk) (version source revid:jorgen.loland@oracle.com-20110110090420-iep4ek5s7klq6rwk) (merge vers: 5.6.2) (pib:24)
[10 Jan 2011 10:13]
Jørgen Løland
Pushed to trunk
[10 Jan 2011 16:46]
Paul DuBois
Noted in 5.6.2 changelog. An uninitialized variable for the index condition pushdown access method could result in a server crash or Valgrind warnings.
[15 Feb 2011 9:12]
Marko Mäkelä
This comment is a duplicate of Bug #59307: [5 Jan 11:16] Jorgen Loland