[MDEV-31247] Assertion `c >= 0' failed in COST_MULT upon query with many joins Created: 2023-05-11  Updated: 2023-05-27  Resolved: 2023-05-27

Status: Closed
Project: MariaDB Server
Component/s: Optimizer
Affects Version/s: 11.0
Fix Version/s: 11.0.2

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Problem/Incident
is caused by MDEV-26974 Improve selectivity and related costs... Closed

 Description   

Unfortunately I was unable to get rid of performance schema and information schema in the query. Replacing I_S and P_S tables with regular or temporary tables with identical contents makes it go away. I hope the analysis will allow to create a better test case. While this one appears to be deterministic, and it fails both in MTR and outside, the dependency on P_S and I_S makes it vulnerable to future changes.

Remember that MTR runs with performance-schema=on and various non-default performance schema settings. They are sufficient for this test case; but if you run it outside MTR, on a standalone server, set at least

--performance-schema=on --performance-schema-instrument='%=ON'


--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (a INT) ENGINE=MyISAM;
 
INSERT INTO t1 VALUES (1),(2);
 
 
 
CREATE TABLE t2 (b INT) ENGINE=MyISAM;
 
 
 
CREATE TABLE t3 (c INT) ENGINE=MyISAM;
 
INSERT INTO t3 VALUES (1),(2),(3);
 
 
 
CREATE TABLE t4 (d CHAR(200), e INT, KEY(e)) ENGINE=Aria;
 
INSERT INTO t4 (e) VALUES (1),(2),(3);
 
 
 
CREATE TABLE t5 (f INT) ENGINE=MyISAM;
 
INSERT INTO t5 VALUES (1),(2),(3),(4),(5),(6);
 
 
 
CREATE ALGORITHM=TEMPTABLE VIEW v AS select THREAD_ID 
  from performance_schema.metadata_locks ml1
 
  join performance_schema.metadata_locks ml2
 
  join performance_schema.threads;
 
 
 
SELECT * FROM information_schema.TABLES 
         JOIN information_schema.TABLE_STATISTICS ts
 
         JOIN performance_schema.events_statements_summary_by_digest d1
 
         JOIN performance_schema.events_waits_summary_by_host_by_event_name
 
         LEFT JOIN (t1 JOIN t2) ON 1
 
         JOIN performance_schema.table_io_waits_summary_by_index_usage
 
         JOIN information_schema.PROCESSLIST
 
         JOIN performance_schema.events_statements_summary_by_digest d2
 
         JOIN performance_schema.memory_summary_by_user_by_event_name
 
         JOIN t3
 
         JOIN t4 ON ts.TABLE_SCHEMA = t4.e
 
         JOIN v ON ts.ROWS_READ = v.THREAD_ID
 
         JOIN t5
 
;
 
 
 
# Cleanup
 
DROP VIEW v;
 
DROP TABLE t1, t2, t3, t4, t5;

11.0 368dd22a

 
mariadbd: /data/src/11.0/sql/optimizer_costs.h:139: double COST_MULT(double, double): Assertion `c >= 0' failed.
 
230511 22:42:19 [ERROR] mysqld got signal 6 ;
 
 
 
#9  0x00007fccd5c53df2 in __GI___assert_fail (assertion=0x561f8419e160 "c >= 0", file=0x561f8419e1a0 "/data/src/11.0/sql/optimizer_costs.h", line=139, function=0x561f8419e280 "double COST_MULT(double, double)") at ./assert/assert.c:101
 
#10 0x0000561f821db877 in COST_MULT (c=-nan(0x8000000000000), f=1) at /data/src/11.0/sql/optimizer_costs.h:139
 
#11 0x0000561f8223da57 in prev_record_reads (position=0x6320000dc408, idx=13, found_ref=2, record_count=1, identical_keys=0x7fccc411e4a0) at /data/src/11.0/sql/sql_select.cc:12045
 
#12 0x0000561f8222956b in best_access_path (join=0x62d00023ed20, s=0x6320000db898, remaining_tables=4096, join_positions=0x6320000dc408, idx=13, disable_jbuf=false, record_count=1, pos=0x6320000ea150, loose_scan_pos=0x6320000ea290) at /data/src/11.0/sql/sql_select.cc:8436
 
#13 0x0000561f8223814b in get_costs_for_tables (join=0x62d00023ed20, remaining_tables=4096, idx=13, record_count=0, trace_one_table=0x7fccc411ece0, pos=0x6320000dc308, store_position=0x7fccc411ec00, allowed_tables=0x7fccc411ec40, stop_on_eq_ref=false) at /data/src/11.0/sql/sql_select.cc:11047
 
#14 0x0000561f82239402 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=4096, idx=13, record_count=0, read_time=1.4626241072177529e+23, search_depth=49, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc411f000) at /data/src/11.0/sql/sql_select.cc:11304
 
#15 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=4112, idx=12, record_count=0, read_time=1.4626241072177529e+23, search_depth=50, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc411f420) at /data/src/11.0/sql/sql_select.cc:11529
 
#16 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=4144, idx=11, record_count=1.37301514518528e+25, read_time=8.9608962032472823e+21, search_depth=51, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc411f860) at /data/src/11.0/sql/sql_select.cc:11529
 
#17 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=4152, idx=10, record_count=2.415919104e+20, read_time=1.4301187573021118e+17, search_depth=52, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc411fca0) at /data/src/11.0/sql/sql_select.cc:11529
 
#18 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=4664, idx=9, record_count=5898240000000000, read_time=3170074936951.3145, search_depth=53, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc4120100) at /data/src/11.0/sql/sql_select.cc:11529
 
#19 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=4728, idx=8, record_count=720000000000, read_time=588202314.09921229, search_depth=54, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc4120560) at /data/src/11.0/sql/sql_select.cc:11529
 
#20 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=4984, idx=7, record_count=3600000000, read_time=2679180.3675826588, search_depth=55, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc41209e0) at /data/src/11.0/sql/sql_select.cc:11529
 
#21 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=4988, idx=6, record_count=18000000, read_time=6524.4021106590008, search_depth=56, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc4120e60) at /data/src/11.0/sql/sql_select.cc:11529
 
#22 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=5116, idx=5, record_count=180000, read_time=186.865240059, search_depth=57, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc4121300) at /data/src/11.0/sql/sql_select.cc:11529
 
#23 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=7164, idx=4, record_count=180000, read_time=40.518791259000004, search_depth=58, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc41217a0) at /data/src/11.0/sql/sql_select.cc:11529
 
#24 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=7166, idx=3, record_count=1800, read_time=0.31538127900000001, search_depth=59, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc4121c60) at /data/src/11.0/sql/sql_select.cc:11529
 
#25 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=7167, idx=2, record_count=18, read_time=0.023333031000000001, search_depth=60, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc4122120) at /data/src/11.0/sql/sql_select.cc:11529
 
#26 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=15359, idx=1, record_count=3, read_time=0.010504815000000001, search_depth=61, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc4122600) at /data/src/11.0/sql/sql_select.cc:11529
 
#27 0x0000561f8223ae50 in best_extension_by_limited_search (join=0x62d00023ed20, remaining_tables=16383, idx=0, record_count=1, read_time=0, search_depth=62, use_cond_selectivity=4, processed_eq_ref_tables=0x7fccc41228d0) at /data/src/11.0/sql/sql_select.cc:11529
 
#28 0x0000561f82233e78 in greedy_search (join=0x62d00023ed20, remaining_tables=16383, search_depth=62, use_cond_selectivity=4) at /data/src/11.0/sql/sql_select.cc:10275
 
#29 0x0000561f8223196c in choose_plan (join=0x62d00023ed20, join_tables=16383, emb_sjm_nest=0x0) at /data/src/11.0/sql/sql_select.cc:9796
 
#30 0x0000561f8221835a in make_join_statistics (join=0x62d00023ed20, tables_list=..., keyuse_array=0x62d00023f088) at /data/src/11.0/sql/sql_select.cc:6085
 
#31 0x0000561f821f3dda in JOIN::optimize_inner (this=0x62d00023ed20) at /data/src/11.0/sql/sql_select.cc:2577
 
#32 0x0000561f821ece47 in JOIN::optimize (this=0x62d00023ed20) at /data/src/11.0/sql/sql_select.cc:1905
 
#33 0x0000561f8220eab3 in mysql_select (thd=0x62b00017a218, tables=0x6290000fad68, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2701396736, result=0x62d000238388, unit=0x62b00017e660, select_lex=0x6290000fa6f0) at /data/src/11.0/sql/sql_select.cc:5144
 
#34 0x0000561f821de6e8 in handle_select (thd=0x62b00017a218, lex=0x62b00017e588, result=0x62d000238388, setup_tables_done_option=0) at /data/src/11.0/sql/sql_select.cc:616
 
#35 0x0000561f82103ac4 in execute_sqlcom_select (thd=0x62b00017a218, all_tables=0x6290000fad68) at /data/src/11.0/sql/sql_parse.cc:6279
 
#36 0x0000561f820f1eeb in mysql_execute_command (thd=0x62b00017a218, is_called_from_prepared_stmt=false) at /data/src/11.0/sql/sql_parse.cc:3949
 
#37 0x0000561f8210e574 in mysql_parse (thd=0x62b00017a218, rawbuf=0x6290000fa238 "SELECT * FROM information_schema.TABLES \nJOIN information_schema.TABLE_STATISTICS ts\nJOIN performance_schema.events_statements_summary_by_digest d1\nJOIN performance_schema.events_waits_summary_by_host"..., length=551, parser_state=0x7fccc4124a20) at /data/src/11.0/sql/sql_parse.cc:8014
 
#38 0x0000561f820e4460 in dispatch_command (command=COM_QUERY, thd=0x62b00017a218, packet=0x629000285219 "SELECT * FROM information_schema.TABLES \nJOIN information_schema.TABLE_STATISTICS ts\nJOIN performance_schema.events_statements_summary_by_digest d1\nJOIN performance_schema.events_waits_summary_by_host"..., packet_length=552, blocking=true) at /data/src/11.0/sql/sql_parse.cc:1894
 
#39 0x0000561f820e1183 in do_command (thd=0x62b00017a218, blocking=true) at /data/src/11.0/sql/sql_parse.cc:1407
 
#40 0x0000561f825a900c in do_handle_one_connection (connect=0x608000003938, put_in_cache=true) at /data/src/11.0/sql/sql_connect.cc:1416
 
#41 0x0000561f825a89cd in handle_one_connection (arg=0x6080000038b8) at /data/src/11.0/sql/sql_connect.cc:1318
 
#42 0x0000561f8319d324 in pfs_spawn_thread (arg=0x617000008218) at /data/src/11.0/storage/perfschema/pfs.cc:2201
 
#43 0x00007fccd5ca7fd4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
 
#44 0x00007fccd5d285bc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

The failure started happening on 11.0 after this commit in 11.0.1:

commit 15e889c3009a1870d1ba2aff74a1e8922d59bce6
 
Author: Monty
 
Date:   Tue Feb 14 15:20:14 2023 +0200
 
 
 
    MDEV-30699: Updated prev_record_reads() to be more exact
 
    
    The old code in prev_record_reads() did give wrong estimates when a



 Comments   
Comment by Michael Widenius [ 2023-05-27 ]

Problem was an overflow when calculating number of join cache refills.

Comment by Michael Widenius [ 2023-05-27 ]

Pushed to 11.0

Generated at Thu Feb 08 10:22:24 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.