Bug #50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
Submitted: 15 Jan 2010 19:45 Modified: 22 Nov 2010 1:09
Reporter: Patrick Crews Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S3 (Non-critical)
Version:6.0 OS:Any
Assigned to: Olav Sandstå CPU Architecture:Any
Tags: crashing bug, mrr, optimizer_switch, pushbuild, rqg_pb2, test failure

[15 Jan 2010 19:45] Patrick Crews
Description:
Crashing bug / failed assertion:
mysqld: handler.h:1283: void COST_VECT::add_io(double, double): Assertion `!(sizeof (avg_io_cost) == sizeof (float) ? __isnanf (avg_io_cost) : sizeof (avg_io_cost) == sizeof (double) ? __isnan (avg_io_cost) : __isnanl (avg_io_cost))' failed.

This is 6.0 only and occurs only if optimizer_use_mrr is set to 'force', setting this variable to 'disable' will remove the crash.

Failing on a simple query:
SELECT table2 .`col_varchar_nokey`
FROM CC table1  STRAIGHT_JOIN A table2  ON table2 .`pk`  < table1 .`pk`   ;

Thread 1 (Thread 6658):
#0  0x005bf422 in __kernel_vsyscall ()
#1  0x00f17e93 in __pthread_kill (threadid=3012433776, signo=6)
    at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:64
#2  0x08cfabb7 in my_write_core (sig=6) at stacktrace.c:328
#3  0x084143af in handle_segfault (sig=6) at mysqld.cc:2815
#4  <signal handler called>
#5  0x005bf422 in __kernel_vsyscall ()
#6  0x0024a4d1 in *__GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#7  0x0024d932 in *__GI_abort () at abort.c:92
#8  0x00243648 in *__GI___assert_fail (
    assertion=0x903f678 "!(sizeof (avg_io_cost) == sizeof (float) ? __isnanf (avg_io_cost) : sizeof (avg_io_cost) == sizeof (double) ? __isnan (avg_io_cost) : __isnanl (avg_io_cost))", file=0x903f66c "handler.h", 
    line=1283, function=0x9041fa0 "void COST_VECT::add_io(double, double)") at assert.c:81
#9  0x08593f85 in COST_VECT::add_io (this=0xb38dbe58, add_io_cnt=-nan(0x8000000000000), 
    add_avg_cost=-nan(0x8000000000000)) at handler.h:1283
#10 0x086f1a1b in COST_VECT::add (this=0xb38dbe58, cost=0xb38dbdb0) at handler.h:1273
#11 0x086ee52b in DsMrr_impl::get_disk_sweep_mrr_cost (this=0xa2ae794, keynr=0, rows=1, flags=12, 
    buffer_size=0xb38dc1e8, cost=0xb38dbe58) at handler.cc:4966
#12 0x086edf6a in DsMrr_impl::choose_mrr_impl (this=0xa2ae794, keyno=0, rows=1, flags=0xb38dc1ec, 
    bufsz=0xb38dc1e8, cost=0xb38dc190) at handler.cc:4877
#13 0x086eda8b in DsMrr_impl::dsmrr_info_const (this=0xa2ae794, keyno=0, seq=0xb38dc128, 
    seq_init_param=0xb38dbf40, n_ranges=0, bufsz=0xb38dc1e8, flags=0xb38dc1ec, cost=0xb38dc190)
    at handler.cc:4791
#14 0x08b8d937 in ha_myisam::multi_range_read_info_const (this=0xa2ae638, keyno=0, seq=0xb38dc128, 
    seq_init_param=0xb38dbf40, n_ranges=0, bufsz=0xb38dc1e8, flags=0xb38dc1ec, cost=0xb38dc190)
    at ha_myisam.cc:2139
#15 0x086b46c9 in check_quick_select (param=0xb38dc318, idx=0, index_only=false, tree=0xa27fea0, 
    update_tbl_stats=true, mrr_flags=0xb38dc1ec, bufsize=0xb38dc1e8, cost=0xb38dc190) at opt_range.cc:7908
#16 0x086a62dd in get_key_scans_params (param=0xb38dc318, tree=0xa27fd68, index_read_must_be_used=false, 
    update_tbl_stats=true, read_time=4.3000000000000007) at opt_range.cc:5038
#17 0x0869ccdb in SQL_SELECT::test_quick_select (this=0xa27f8b0, thd=0xa2612b8, keys_to_use=..., 
    prev_tables=0, limit=18446744073709551615, force_quick_range=false, ordered_output=false)
    at opt_range.cc:2479
#18 0x08576a24 in test_if_quick_select (tab=0xa27f6f4) at sql_select.cc:17363
#19 0x08576804 in join_init_quick_read_record (tab=0xa27f6f4) at sql_select.cc:17343
#20 0x08572cca in sub_select (join=0xa34c638, join_tab=0xa27f6f4, end_of_records=false)
    at sql_select.cc:16504
#21 0x0857411e in evaluate_join_record (join=0xa34c638, join_tab=0xa27f538, error=0)
    at sql_select.cc:16797
#22 0x08572d73 in sub_select (join=0xa34c638, join_tab=0xa27f538, end_of_records=false)
    at sql_select.cc:16509
#23 0x085716d8 in do_select (join=0xa34c638, fields=0xa262798, table=0x0, procedure=0x0)
    at sql_select.cc:16053
#24 0x08537d81 in JOIN::exec (this=0xa34c638) at sql_select.cc:2946
#25 0x08538a4a in mysql_select (thd=0xa2612b8, rref_pointer_array=0xa262808, tables=0xa27df68, 
    wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, 
    select_options=2147748608, result=0xa27ef98, unit=0xa26223c, select_lex=0xa262704)
    at sql_select.cc:3137
#26 0x085291e5 in handle_select (thd=0xa2612b8, lex=0xa2621e0, result=0xa27ef98, 
    setup_tables_done_option=0) at sql_select.cc:304
#27 0x0844c3ab in execute_sqlcom_select (thd=0xa2612b8, all_tables=0xa27df68) at sql_parse.cc:4940
#28 0x0843abf0 in mysql_execute_command (thd=0xa2612b8) at sql_parse.cc:2165
#29 0x08450450 in mysql_parse (thd=0xa2612b8, 
    inBuf=0xa27dd18 "SELECT table2 .`col_varchar_nokey`  \nFROM CC table1  STRAIGHT_JOIN A table2  ON table2 .`pk`  < table1 .`pk`", length=108, found_semicolon=0xb38e090c) at sql_parse.cc:5971
#30 0x08435e67 in dispatch_command (command=COM_QUERY, thd=0xa2612b8, packet=0xa285b69 "", 
    packet_length=111) at sql_parse.cc:1090
#31 0x084346b7 in do_command (thd=0xa2612b8) at sql_parse.cc:774
#32 0x08430a35 in do_handle_one_connection (thd_arg=0xa2612b8) at sql_connect.cc:1173
#33 0x0843071c in handle_one_connection (arg=0xa2612b8) at sql_connect.cc:1113
#34 0x08e5c497 in pfs_spawn_thread (arg=0xa2f5020) at pfs.cc:1011
#35 0x00f1280e in start_thread (arg=0xb38e1770) at pthread_create.c:300
#36 0x002ec8de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

How to repeat:
#/* Server0: MySQL 6.0.14-alpha-gcov-debug-log */

/*!50400 SET SESSION optimizer_switch = 'index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,engine_condition_pushdown=on,firstmatch=on,loosescan=on,materialization=on,semijoin=on' */;
/*!50400 SET SESSION optimizer_use_mrr = 'force' */;
/*!50400 SET SESSION engine_condition_pushdown = 'ON' */;
/*!50400 SET SESSION join_cache_level = 1 */;
/*!50400 SET SESSION debug = '' */;

#/* Begin test case for query 0 */

--disable_warnings
DROP TABLE /*! IF EXISTS */ A;
DROP TABLE /*! IF EXISTS */ CC;
--enable_warnings

CREATE TABLE `A` (
  `pk` int(11) NOT NULL AUTO_INCREMENT,
  `col_varchar_nokey` varchar(1) DEFAULT NULL,
  PRIMARY KEY (`pk`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1;
CREATE TABLE `CC` (
  `pk` int(11) NOT NULL AUTO_INCREMENT,
  `col_varchar_nokey` varchar(1) DEFAULT NULL,
  PRIMARY KEY (`pk`)
) ENGINE=MyISAM AUTO_INCREMENT=30 DEFAULT CHARSET=latin1;
INSERT INTO `CC` VALUES (10,'v');
INSERT INTO `CC` VALUES (11,'r');
INSERT INTO `CC` VALUES (12,'a');
INSERT INTO `CC` VALUES (13,'m');
INSERT INTO `CC` VALUES (14,'y');
INSERT INTO `CC` VALUES (15,'j');
INSERT INTO `CC` VALUES (16,'d');
INSERT INTO `CC` VALUES (17,'z');
INSERT INTO `CC` VALUES (18,'e');
INSERT INTO `CC` VALUES (19,'h');
INSERT INTO `CC` VALUES (20,'b');
INSERT INTO `CC` VALUES (21,'s');
INSERT INTO `CC` VALUES (22,'e');
INSERT INTO `CC` VALUES (23,'j');
INSERT INTO `CC` VALUES (24,'e');
INSERT INTO `CC` VALUES (25,'f');
INSERT INTO `CC` VALUES (26,'v');
INSERT INTO `CC` VALUES (27,'x');
INSERT INTO `CC` VALUES (28,'m');
INSERT INTO `CC` VALUES (29,'c');

 
SELECT table2 .`col_varchar_nokey`  
FROM CC table1  STRAIGHT_JOIN A table2  ON table2 .`pk`  < table1 .`pk`   ;

DROP TABLE A;
DROP TABLE CC;
#/* End of test case for query 0 */
[18 Feb 2010 12:29] John Embretsen
This bug looks like the cause of the Random Query Generator test rqg_info_schema failing in the mysql-6.0-codebase-bugfixing branch. 

The stand-alone query causing server crash is:

SELECT *
FROM (INFORMATION_SCHEMA.PLUGINS AS table1
    STRAIGHT_JOIN mysql.ndb_binlog_index AS table2
    ON ( table2.deletes = table1.PLUGIN_LICENSE ) )
WHERE  ( table1.PLUGIN_STATUS != table1.PLUGIN_NAME
     AND table2.epoch > 'vd');

Closer inspection shows that this test failure started occurring January 15 2010 after the push of a fix for Bug#50237, bzr revid tor.didriksen@sun.com-20100115121255-26i42spl5b1bg1o9.
[1 Mar 2010 14: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/101877
[16 Mar 2010 17: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/103499

3824 Olav.Sandstaa@sun.com	2010-03-16
      Fix for Bug#50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
      
      The crash occured when an assert was checking that the value for the
      average IO cost in the cost vector did not have the value NaN. The NaN
      value was introduced in the cost vector object in get_sweep_read_cost()
      when the size of the data file for the table was 0 byte (ie. empty
      data file).  This resulted in a division by zero when computing the
      estimated number of blocks needed to be read from disk.
      
      The fix for avoiding the division by zero is to assume that the data
      file always contains at least one block. This is similar to what is
      done for the estimated number of blocks to be accessed. So after this
      fix the cost estimate in get_sweep_read_cost() will assume both that
      the data file and the estimate for number of blocks to access are at
      least 1.
     @ mysql-test/include/mrr_tests.inc
        Test for Bug#50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
     @ mysql-test/r/innodb_mrr.result
        Result file for test for Bug#50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
     @ mysql-test/r/myisam_mrr.result
        Result file for test for Bug#50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
     @ sql/handler.cc
        In get_sweep_read_cost: To avoid a division by zero when computing
        the estimated number of "busy blocks" when the data file has zero
        length we assume that the data file contains at least one block.
[16 Mar 2010 18:01] Olav Sandstå
Pushed to mysql-6.0-codebase-bugfixing with revision id:
olav.sandstaa@sun.com-20100316175401-iax4ockzqybjrjpl .
[24 Mar 2010 8:14] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100324081249-yfwol7qtcek6dh7w) (version source revid:alik@sun.com-20100324081113-kc7x1iytnplww91u) (merge vers: 6.0.14-alpha) (pib:16)
[25 Mar 2010 1:22] Paul DuBois
Noted in 6.0.14 changelog.

The optimizer raised an assertion due to a divide-by-zero error
during I/O cost estimation.
[7 May 2010 14:16] 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/107764

3151 Olav Sandstaa	2010-05-07
      Fix for Bug#50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
      
      (backporting of revid:olav.sandstaa@sun.com-20100316175401-iax4ockzqybjrjpl)
            
      The crash occured when an assert was checking that the value for the
      average IO cost in the cost vector did not have the value NaN. The NaN
      value was introduced in the cost vector object in get_sweep_read_cost()
      when the size of the data file for the table was 0 byte (ie. empty
      data file).  This resulted in a division by zero when computing the
      estimated number of blocks needed to be read from disk.
            
      The fix for avoiding the division by zero is to assume that the data
      file always contains at least one block. This is similar to what is
      done for the estimated number of blocks to be accessed. So after this
      fix the cost estimate in get_sweep_read_cost() will assume both that
      the data file and the estimate for number of blocks to access are at
      least 1.
     @ mysql-test/include/mrr_tests.inc
        Test for Bug#50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
     @ mysql-test/r/innodb_mrr.result
        Result file for test for Bug#50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
     @ mysql-test/r/myisam_mrr.result
        Result file for test for Bug#50381 Assertion failing in handler.h:1283: void COST_VECT::add_io(double, double)
     @ sql/handler.cc
        In get_sweep_read_cost: To avoid a division by zero when computing
        the estimated number of "busy blocks" when the data file has zero
        length we assume that the data file contains at least one block.
[16 Aug 2010 6:40] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100816062819-bluwgdq8q4xysmlg) (version source revid:alik@sun.com-20100816062612-enatdwnv809iw3s9) (pib:20)
[13 Nov 2010 16:20] Bugs System
Pushed into mysql-trunk 5.6.99-m5 (revid:alexander.nozdrin@oracle.com-20101113155825-czmva9kg4n31anmu) (version source revid:vasil.dimov@oracle.com-20100629074804-359l9m9gniauxr94) (merge vers: 5.6.99-m4) (pib:21)
[22 Nov 2010 1:09] Paul DuBois
Noted in 5.6.1 changelog.
[23 Nov 2010 2:27] Paul DuBois
Correction: No 5.6.1 changelog entry. Bug does not appear in any released 5.6.x version.