[MDEV-22882] Assertion `m_psi_batch_mode == PSI_BATCH_MODE_NONE' failed in handler::ha_close on UNION query when limiting tmp/heap size Created: 2020-06-13  Updated: 2023-03-03

Status: Confirmed
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.5, 10.6, 10.7
Fix Version/s: 10.5, 10.6

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Igor Babaev
Resolution: Unresolved Votes: 0
Labels: affects-tests, not-10.1, not-10.2, not-10.3, not-10.4, regression

Issue Links:
Relates
relates to MDEV-22391 Assertion `0' failed in Item_type_hol... Closed
relates to MDEV-22104 Assertion `m_psi_batch_mode == PSI_BA... Confirmed

 Description    

SET SESSION max_heap_table_size=16384;
 
WITH RECURSIVE q (b) AS (SELECT 1 UNION ALL SELECT 1+b FROM q WHERE b<2000) SELECT MIN(q.b),MAX(q.b),AVG(q.b) FROM q, q AS q1;

Leads to:

10.5.4 6877ef9a7c9c7ee55d67e4baaf4e8f7b874c9f89

 
mysqld: /test/10.5_dbg/sql/handler.cc:2965: int handler::ha_close(): Assertion `m_psi_batch_mode == PSI_BATCH_MODE_NONE' failed.

10.5.4 6877ef9a7c9c7ee55d67e4baaf4e8f7b874c9f89

 
Core was generated by `/test/MD060620-mariadb-10.5.4-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
[Current thread is 1 (Thread 0x1525be10c700 (LWP 2335918))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x000055629922b00d in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
 
#2  0x00005562989d4bbc in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:330
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#5  0x00001525c6a6a801 in __GI_abort () at abort.c:79
 
#6  0x00001525c6a5a39a in __assert_fail_base (fmt=0x1525c6be17d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55629953db48 "m_psi_batch_mode == PSI_BATCH_MODE_NONE", file=file@entry=0x55629953c562 "/test/10.5_dbg/sql/handler.cc", line=line@entry=2965, function=function@entry=0x556299540bf0 <handler::ha_close()::__PRETTY_FUNCTION__> "int handler::ha_close()") at assert.c:92
 
#7  0x00001525c6a5a412 in __GI___assert_fail (assertion=assertion@entry=0x55629953db48 "m_psi_batch_mode == PSI_BATCH_MODE_NONE", file=file@entry=0x55629953c562 "/test/10.5_dbg/sql/handler.cc", line=line@entry=2965, function=function@entry=0x556299540bf0 <handler::ha_close()::__PRETTY_FUNCTION__> "int handler::ha_close()") at assert.c:101
 
#8  0x00005562989dbe5b in handler::ha_close (this=0x1525a4c83ca0) at /test/10.5_dbg/sql/handler.cc:2965
 
#9  0x0000556298779ed5 in create_internal_tmp_table_from_heap (thd=thd@entry=0x1525a4c15088, table=table@entry=0x1525a4ca70a0, start_recinfo=<optimized out>, recinfo=recinfo@entry=0x1525a4c79400, error=error@entry=135, ignore_last_dupp_key_error=ignore_last_dupp_key_error@entry=true, is_duplicate=0x1525be109fc0) at /test/10.5_dbg/sql/sql_select.cc:19872
 
#10 0x000055629883aa86 in TABLE::insert_all_rows_into_tmp_table (this=0x1525a4c800a0, thd=thd@entry=0x1525a4c15088, tmp_table=0x1525a4ca70a0, tmp_table_param=0x1525a4c793c0, with_cleanup=with_cleanup@entry=true) at /test/10.5_dbg/sql/table.cc:8985
 
#11 0x00005562986dd9fd in TABLE_LIST::fill_recursive (this=this@entry=0x1525a4c77d38, thd=thd@entry=0x1525a4c15088) at /test/10.5_dbg/sql/sql_derived.cc:1148
 
#12 0x00005562986ddd9e in mysql_derived_fill (thd=0x1525a4c15088, lex=0x1525a4c18fd8, derived=0x1525a4c77d38) at /test/10.5_dbg/sql/sql_derived.cc:1240
 
#13 0x00005562986dd8c3 in mysql_handle_single_derived (lex=0x1525a4c18fd8, derived=derived@entry=0x1525a4c77d38, phases=phases@entry=96) at /test/10.5_dbg/sql/sql_derived.cc:206
 
#14 0x000055629876fbe9 in st_join_table::preread_init (this=this@entry=0x1525a4caa4d8) at /test/10.5_dbg/sql/sql_select.cc:13597
 
#15 0x0000556298780679 in join_init_read_record (tab=0x1525a4caa4d8) at /test/10.5_dbg/sql/sql_select.cc:21567
 
#16 0x00005562988bf6f6 in JOIN_TAB_SCAN::open (this=0x1525a4caaf28) at /test/10.5_dbg/sql/sql_join_cache.cc:3357
 
#17 0x00005562988c2b0b in JOIN_CACHE::join_matching_records (this=0x1525a4caac28, skip_last=false) at /test/10.5_dbg/sql/sql_join_cache.cc:2260
 
#18 0x00005562988c2370 in JOIN_CACHE::join_records (this=this@entry=0x1525a4caac28, skip_last=skip_last@entry=false) at /test/10.5_dbg/sql/sql_join_cache.cc:2092
 
#19 0x0000556298770462 in sub_select_cache (join=0x1525a4c78d30, join_tab=0x1525a4caa4d8, end_of_records=<optimized out>) at /test/10.5_dbg/sql/sql_select.cc:20423
 
#20 0x0000556298768b79 in evaluate_join_record (join=join@entry=0x1525a4c78d30, join_tab=join_tab@entry=0x1525a4caa130, error=error@entry=0) at /test/10.5_dbg/sql/sql_select.cc:20852
 
#21 0x0000556298770056 in sub_select (join=0x1525a4c78d30, join_tab=0x1525a4caa130, end_of_records=<optimized out>) at /test/10.5_dbg/sql/sql_select.cc:20668
 
#22 0x00005562987a8d44 in do_select (procedure=0x0, join=0x1525a4c78d30) at /test/10.5_dbg/sql/sql_select.cc:20163
 
#23 JOIN::exec_inner (this=this@entry=0x1525a4c78d30) at /test/10.5_dbg/sql/sql_select.cc:4475
 
#24 0x00005562987a935f in JOIN::exec (this=this@entry=0x1525a4c78d30) at /test/10.5_dbg/sql/sql_select.cc:4256
 
#25 0x00005562987a7674 in mysql_select (thd=thd@entry=0x1525a4c15088, tables=<optimized out>, fields=@0x1525a4c76950: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x1525a4c76f20, last = 0x1525a4c775a8, elements = 3}, <No data fields>}, conds=0x0, og_num=0, order=<optimized out>, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x1525a4c78d08, unit=0x1525a4c190a0, select_lex=0x1525a4c76800) at /test/10.5_dbg/sql/sql_select.cc:4680
 
#26 0x00005562987a79a3 in handle_select (thd=thd@entry=0x1525a4c15088, lex=lex@entry=0x1525a4c18fd8, result=result@entry=0x1525a4c78d08, setup_tables_done_option=setup_tables_done_option@entry=0) at /test/10.5_dbg/sql/sql_select.cc:417
 
#27 0x00005562987313a0 in execute_sqlcom_select (thd=thd@entry=0x1525a4c15088, all_tables=0x1525a4c77600) at /test/10.5_dbg/sql/sql_parse.cc:6208
 
#28 0x000055629872a4cc in mysql_execute_command (thd=thd@entry=0x1525a4c15088) at /test/10.5_dbg/sql/sql_parse.cc:3939
 
#29 0x0000556298737322 in mysql_parse (thd=thd@entry=0x1525a4c15088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1525be10b350, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:7992
 
#30 0x0000556298723e1c in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1525a4c15088, packet=packet@entry=0x1525a4c67089 "", packet_length=packet_length@entry=125, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:1874
 
#31 0x00005562987225f6 in do_command (thd=0x1525a4c15088) at /test/10.5_dbg/sql/sql_parse.cc:1355
 
#32 0x000055629887d9f9 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x1525a81153a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1411
 
#33 0x000055629887e115 in handle_one_connection (arg=arg@entry=0x1525a81153a8) at /test/10.5_dbg/sql/sql_connect.cc:1313
 
#34 0x0000556298cdd104 in pfs_spawn_thread (arg=0x1525c5445888) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
 
#35 0x00001525c774d6db in start_thread (arg=0x1525be10c700) at pthread_create.c:463
 
#36 0x00001525c6b4b88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.5.4 (dbg, 6877ef9a7c9c7ee55d67e4baaf4e8f7b874c9f89)

Bug confirmed not present in:
MariaDB: 10.1.46 (dbg), 10.1.46 (opt), 10.2.33 (dbg), 10.2.33 (opt), 10.3.24 (dbg), 10.3.24 (opt), 10.4.14 (dbg), 10.4.14 (opt), 10.5.4 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

Interestingly, this bug does not crash the later revision 07d1c8567cbfe94398a9857c47fb9919cad42651. Perhaps a relevant change was made or the bug is now somehow masked? Output from that version;

10.5.4 07d1c8567cbfe94398a9857c47fb9919cad42651

 
10.5.4>SET SESSION max_heap_table_size=16384;
 
Query OK, 0 rows affected (0.000 sec)
 
 
 
10.5.4>WITH RECURSIVE q (b) AS (SELECT 1 UNION ALL SELECT 1+b FROM q WHERE b<2000) SELECT MIN(q.b),MAX(q.b),AVG(q.b) FROM q, q AS q1;
 
+----------+----------+-----------+
 
| MIN(q.b) | MAX(q.b) | AVG(q.b)  |
 
+----------+----------+-----------+
 
|        1 |     2000 | 1000.5000 |
 
+----------+----------+-----------+
 
1 row in set (0.692 sec)



 Comments   
Comment by Roel Van de Paar [ 2020-06-13 ]

Another different testcase leading to the same assert. Again only on the older revision of 10.5.4 quoted above, newer revision seems fine.

USE test;
 
CREATE TABLE t (a INT) ROW_FORMAT=compressed, ENGINE=InnoDB;
 
ALTER TABLE t ADD COLUMN c2 INTEGER COMMENT 'a';
 
SET tmp_table_size=100;
 
INSERT INTO t  VALUES (94, 46), (31, 438), (61, 152), (78, 123), (88, 411), (122, 118), (0, 177), (75, 42), (108, 67), (79, 349), (59, 188), (68, 206), (49, 345);
 
SELECT * FROM ( SELECT * FROM t UNION SELECT * FROM t) a,(SELECT * FROM t UNION SELECT * FROM t) b;

Comment by Roel Van de Paar [ 2020-06-13 ]

Another one, again same outcomes and version difference as above. No specific mention of UNION, but two SELECT's are combined in a similar fashion.

USE test;
 
SET SQL_MODE='';
 
SET SESSION tmp_table_size=True;
 
CREATE TABLE t (f INT(10) UNSIGNED NOT NULL) ENGINE=InnoDB;
 
INSERT INTO t VALUES (CONVERT(_ucs2 0x062F06390648062A0650 USING utf8));
 
insert INTO t SELECT REPEAT('abcdefghijklmnopqrstuvwxyz',100);
 
INSERT INTO t VALUES(0xAAB6);
 
CREATE TEMPORARY TABLE t (e INT, f INT, PRIMARY KEY (f)) ENGINE=InnoDB;
 
SET SESSION OPTIMIZER_SWITCH="derived_merge=OFF";
 
DROP TABLE t;
 
SELECT 1 FROM ((SELECT * FROM (SELECT * FROM t) AS a) AS a, (SELECT * FROM t) AS b);

Comment by Roel Van de Paar [ 2020-06-13 ]

bar Related to MDEV-22391 change Perhaps?

Comment by Roel Van de Paar [ 2020-06-13 ]

MDEV-22104 is related and informative.

Comment by Roel Van de Paar [ 2020-06-13 ]

This bug is (or better; was) seen very often in my runs.

Comment by Roel Van de Paar [ 2020-06-13 ]

At least two different stacks at play. Unique ID's seen:

m_psi_batch_mode == PSI_BATCH_MODE_NONE|SIGABRT|handler::ha_close|create_internal_tmp_table_from_heap|select_unit::write_record|select_unit::send_data 
m_psi_batch_mode == PSI_BATCH_MODE_NONE|SIGABRT|handler::ha_close|create_internal_tmp_table_from_heap|TABLE::insert_all_rows_into_tmp_table|TABLE_LIST::fill_recursive

Comment by Roel Van de Paar [ 2020-06-13 ]

Some more testcases. Again same result; not reproducible on later revision.

USE test;
 
CREATE TABLE t1(str CHAR (255),key str (str(2)));
 
INSERT INTO t1 VALUES (0xACB1);
 
INSERT INTO t1 VALUES (ST_GeomFromText('POINT(698291409 615419376)'));
 
SET SESSION tmp_table_size=47;
 
INSERT INTO t1 VALUES (@inserted_value);
 
SELECT * FROM (SELECT * FROM t1 UNION SELECT * FROM t1) a, (SELECT * FROM t1 UNION SELECT * FROM t1 ) b;


USE test;
 
CREATE TABLE t1 (a INT NOT NULL AUTO_INCREMENT PRIMARY KEY, b VARCHAR(10), c CHAR(254)) ;
 
SET SESSION tmp_table_size=86;
 
INSERT INTO t1  VALUES (1,1,"ab"),(2,2,"cde"),(3,1,"12345"),(4,4,"random"),(5,NULL,NULL),(6,5,NULL),(7,NULL,"lmnopqr");
 
SELECT * FROM (SELECT * FROM t1 UNION SELECT * FROM t1) a, (SELECT * FROM t1 UNION SELECT * FROM t1 ) b;

Comment by Roel Van de Paar [ 2020-06-13 ]

Bar was able to reproduce at c92f7e287fc0e21dc1b181284b1f8e2139d1c331 (Jun 11 10 PM). Also he thinks that the two issues are not related. Thanks bar

Comment by Oleksandr Byelkin [ 2021-06-09 ]

The problem probably connected to the fact that we execute CTE in other way. So ported batch mode for information schema can not take it into account.

Comment by Alice Sherepa [ 2022-01-04 ]

still reproducible on 10.5:

10.5 89a0364fc88efa7d91d028

 
mariadbd: /10.5/src/sql/handler.cc:3056: int handler::ha_close(): Assertion `m_psi_batch_mode == PSI_BATCH_MODE_NONE' failed.
 
220104 20:13:30 [ERROR] mysqld got signal 6 ;
 
 
 
Server version: 10.5.14-MariaDB-debug-log
 
 
 
sql/handler.cc:3057(handler::ha_close())[0x5564827a0d2d]
 
sql/sql_select.cc:20113(create_internal_tmp_table_from_heap(THD*, TABLE*, st_maria_columndef*, st_maria_columndef**, int, bool, bool*))[0x5564820c38b6]
 
sql/table.cc:9096(TABLE::insert_all_rows_into_tmp_table(THD*, TABLE*, TMP_TABLE_PARAM*, bool))[0x5564822fac2e]
 
sql/sql_derived.cc:1171(TABLE_LIST::fill_recursive(THD*))[0x556481e9a1a7]
 
sql/sql_derived.cc:1262(mysql_derived_fill(THD*, LEX*, TABLE_LIST*))[0x556481e9abde]
 
sql/sql_derived.cc:200(mysql_handle_single_derived(LEX*, TABLE_LIST*, unsigned int))[0x556481e936f5]
 
sql/sql_select.cc:13741(st_join_table::preread_init())[0x556482094fe5]
 
sql/sql_select.cc:21846(join_init_read_record(st_join_table*))[0x5564820cf1c3]
 
sql/sql_join_cache.cc:3427(JOIN_TAB_SCAN::open())[0x55648247a7ef]
 
sql/sql_join_cache.cc:2329(JOIN_CACHE::join_matching_records(bool))[0x5564824756a2]
 
sql/sql_join_cache.cc:2151(JOIN_CACHE::join_records(bool))[0x5564824744de]
 
sql/sql_select.cc:20682(sub_select_cache(JOIN*, st_join_table*, bool))[0x5564820c795d]
 
sql/sql_select.cc:21118(evaluate_join_record(JOIN*, st_join_table*, int))[0x5564820c9cd6]
 
sql/sql_select.cc:20927(sub_select(JOIN*, st_join_table*, bool))[0x5564820c8c0d]
 
sql/sql_select.cc:20420(do_select(JOIN*, Procedure*))[0x5564820c64c8]
 
sql/sql_select.cc:4516(JOIN::exec_inner())[0x556482051e14]
 
sql/sql_select.cc:4297(JOIN::exec())[0x55648204f41e]
 
sql/sql_select.cc:4775(mysql_select(THD*, TABLE_LIST*, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*))[0x556482053863]
 
sql/sql_select.cc:444(handle_select(THD*, LEX*, select_result*, unsigned long))[0x556482024d53]
 
sql/sql_parse.cc:6314(execute_sqlcom_select(THD*, TABLE_LIST*))[0x556481f8cb42]
 
sql/sql_parse.cc:4005(mysql_execute_command(THD*))[0x556481f7bae3]
 
sql/sql_parse.cc:8100(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x556481f97e9c]
 
sql/sql_parse.cc:1894(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x556481f6dd57]
 
sql/sql_parse.cc:1370(do_command(THD*))[0x556481f6a696]
 
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x5564823b5c73]
 
sql/sql_connect.cc:1314(handle_one_connection)[0x5564823b548c]
 
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x5564830d5005]
 
nptl/pthread_create.c:478(start_thread)[0x7fa0211c8609]
 
??:0(clone)[0x7fa020d9b293]
 
 
 
Query (0x62b0000852a8): WITH RECURSIVE q (b) AS (SELECT 1 UNION ALL SELECT 1+b FROM q WHERE b<2000) SELECT MIN(q.b),MAX(q.b),AVG(q.b) FROM q, q AS q1

Generated at Thu Feb 08 09:18:11 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.