[MDEV-25927] Assertion `status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory' failed in THD::~THD on PREPARE and SHUTDOWN, Warning: Memory not freed: 16448/16496/16808 Created: 2021-06-15  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11, 11.0
Fix Version/s: 10.4, 10.5, 10.6, 10.11

Type: Bug Priority: Critical
Reporter: Roel Van de Paar Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: Memory_leak, affects-tests, stack-smashing

Issue Links:
Relates
relates to MDEV-21837 Assertion `status_var.local_memory_us... Open

 Description   

Correct test is

CREATE TABLE t (c1 INT, c2 DATE) TABLESPACE t STORAGE MEMORY;
  
--let $_server_id= `SELECT @@server_id`
--let $_expect_file_name= $MYSQLTEST_VARDIR/tmp/mysqld.$_server_id.expect
--exec echo "wait" > $_expect_file_name
 
--connect (c1,localhost,root,,)
 
--error ER_WRONG_NUMBER_OF_COLUMNS_IN_SELECT
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
 
--send shutdown
--connection default
--source include/wait_until_disconnected.inc
 
--exec echo "restart" > $_expect_file_name
--enable_reconnect
--source include/wait_until_connected_again.inc
 
drop table t;

Possibly related to MDEV-21837, though there are some differences.

CREATE TABLE t (c1 INT, c2 DATE) TABLESPACE t STORAGE MEMORY;
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
SHUTDOWN;

Leads to:

10.6.2 6c39eaeb126328e7813b146ecf652d51e4508981 (Debug)

mysqld: /test/10.6_dbg/sql/sql_class.cc:1745: virtual THD::~THD(): Assertion `status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory' failed.

10.6.2 6c39eaeb126328e7813b146ecf652d51e4508981 (Debug)

Core was generated by `/test/MD120621-mariadb-10.6.2-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x150470d4a700 (LWP 3945354))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x0000150473908859 in __GI_abort () at abort.c:79
#2  0x0000150473908729 in __assert_fail_base (fmt=0x150473a9e588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5648de91ede8 "status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory", file=0x5648de91d068 "/test/10.6_dbg/sql/sql_class.cc", line=1745, function=<optimized out>) at assert.c:92
#3  0x0000150473919f36 in __GI___assert_fail (assertion=assertion@entry=0x5648de91ede8 "status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory", file=file@entry=0x5648de91d068 "/test/10.6_dbg/sql/sql_class.cc", line=line@entry=1745, function=function@entry=0x5648de91fc50 "virtual THD::~THD()") at assert.c:101
#4  0x00005648ddc25b6f in THD::~THD (this=0x15042c000db8, __in_chrg=<optimized out>) at /test/10.6_dbg/sql/sql_class.cc:1745
#5  0x00005648ddc25ba1 in THD::~THD (this=0x15042c000db8, __in_chrg=<optimized out>) at /test/10.6_dbg/sql/sql_class.cc:1660
#6  0x00005648dddf1162 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5648e0bdd418, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1451
#7  0x00005648dddf1293 in handle_one_connection (arg=arg@entry=0x5648e0bdd418) at /test/10.6_dbg/sql/sql_connect.cc:1312
#8  0x00005648de29f166 in pfs_spawn_thread (arg=0x5648e0ac6078) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
#9  0x0000150473e16609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x0000150473a05293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.39 (dbg), 10.3.30 (dbg), 10.4.20 (dbg), 10.5.11 (dbg), 10.6.2 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.39 (opt), 10.3.30 (opt), 10.4.20 (opt), 10.5.11 (opt), 10.6.2 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.34 (dbg), 5.7.34 (opt), 8.0.24 (dbg), 8.0.24 (opt)



 Comments   
Comment by Roel Van de Paar [ 2021-06-15 ]

Also try:

CREATE TABLE t (a INT,b INT) ENGINE=InnoDB;
PREPARE s FROM 'WITH RECURSIVE cte AS (SELECT * FROM t WHERE a=1 UNION ALL SELECT a+1 FROM cte WHERE a<?) SELECT * FROM cte AS cte1,cte AS cte2';
SHUTDOWN;

Comment by Roel Van de Paar [ 2021-06-15 ]

UniqueID's seen (note the one_thread_per_connection_end one):

status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory|SIGABRT|THD::~THD|THD::~THD|do_handle_one_connection|handle_one_connection
status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory|SIGABRT|THD::~THD|THD::~THD|one_thread_per_connection_end|do_handle_one_connection
status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory|SIGABRT|Backtrace stopped: Cannot access memory at address
status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory|SIGABRT|__isoc99_fscanf@plt
status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory|SIGABRT|Diagnostics_area::set_error_status|THD::raise_condition|THD::raise_condition|my_message_sql
open_tables == __null|SIGABRT|Diagnostics_area::set_ok_status|my_ok|mysql_rm_table|mysql_execute_command

Comment by Roel Van de Paar [ 2021-11-13 ]

Stack smashing/corruption

CREATE TABLE t (a INT);
ALTER TABLE t ADD COLUMN (b INT);
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
SHUTDOWN;

Leads to:

10.8.0 bc57ff7cf79504a198d4752b4748340a4afd886c (Debug)

mysqld: /test/10.8_dbg/sql/sql_class.cc:1745: virtual THD::~THD(): Assertion `status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory' failed.

10.8.0 bc57ff7cf79504a198d4752b4748340a4afd886c (Debug)

Core was generated by `/test/MD121121-mariadb-10.8.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00001530c34f818b in ?? ()
[Current thread is 1 (LWP 2328496)]
(gdb) bt
#0  0x00001530c34f818b in ?? ()
#1  0x0000000000087007 in ?? ()
#2  0x00001530c354f850 in ?? ()
#3  0x00001530fbad8000 in ?? ()
#4  0x0000153074028020 in ?? ()
#5  0x0000153074028085 in ?? ()
#6  0x0000153074028020 in ?? ()
#7  0x0000153074028020 in ?? ()
#8  0x00001530740280be in ?? ()
#9  0x000015307402814c in ?? ()
#10 0x0000153074028020 in ?? ()
#11 0x000015307402814c in ?? ()
#12 0x0000000000000000 in ?? ()

And

10.8.0 bc57ff7cf79504a198d4752b4748340a4afd886c (Debug)

Core was generated by `/test/MD121121-mariadb-10.8.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGABRT, Aborted.
#0  0x000014ba1853918b in ?? ()
[Current thread is 1 (LWP 3208565)]
(gdb) bt
#0  0x000014ba1853918b in ?? ()
Backtrace stopped: Cannot access memory at address 0x14ba18076a00

Bug confirmed present in:
MariaDB: 10.2.42 (dbg), 10.3.33 (dbg), 10.4.23 (dbg), 10.5.14 (dbg), 10.6.6 (dbg), 10.7.2 (dbg), 10.8.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.42 (opt), 10.3.33 (opt), 10.4.23 (opt), 10.5.14 (opt), 10.6.6 (opt), 10.7.2 (opt), 10.8.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.36 (dbg), 5.7.36 (opt), 8.0.27 (dbg), 8.0.27 (opt)

Comment by Oleksandr Byelkin [ 2022-06-23 ]

can't repeat:

query 'PREPARE s FROM 'WITH RECURSIVE cte AS (SELECT * FROM t WHERE a=1 UNION ALL SELECT a+1 FROM cte WHERE a<?) SELECT * FROM cte AS cte1,cte AS cte2'' failed: 1222: The used SELECT statements have a different number of columns

Comment by Oleksandr Byelkin [ 2022-06-23 ]

correct test case is following:

CREATE TABLE t (c1 INT, c2 DATE) TABLESPACE t STORAGE MEMORY;
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1,2 FROM d) SELECT * FROM d AS d1,d AS d2';
SHUTDOWN;

(finding if it really crash or it is a shutdown)

Comment by Oleksandr Byelkin [ 2022-06-23 ]

this pass:

CREATE TABLE t (c1 INT, c2 DATE) TABLESPACE t STORAGE MEMORY;
 
--let $_server_id= `SELECT @@server_id`
--let $_expect_file_name= $MYSQLTEST_VARDIR/tmp/mysqld.$_server_id.expect
--exec echo "wait" > $_expect_file_name
 
--connect (c1,localhost,root,,)
 
 
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1,2 FROM d) SELECT * FROM d AS d1,d AS d2';
 
--send shutdown
--connection default
--source include/wait_until_disconnected.inc
 
--exec echo "restart" > $_expect_file_name
--enable_reconnect
--source include/wait_until_connected_again.inc
 
drop table t;

Comment by Roel Van de Paar [ 2022-06-23 ]

This crashes as described when executed at the CLI:

10.10.0 081a284712bb661349e2e3802077b12211cede3e (Debug)

10.10.0-dbg>CREATE TABLE t (c1 INT, c2 DATE) TABLESPACE t STORAGE MEMORY;
Query OK, 0 rows affected (0.017 sec)
 
10.10.0-dbg>PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
ERROR 1222 (21000): The used SELECT statements have a different number of columns
10.10.0-dbg>SHUTDOWN;
Query OK, 0 rows affected (0.000 sec)
 
10.10.0-dbg>exit
Bye
qa-roel-2:/test/MD310522-mariadb-10.10.0-linux-x86_64-dbg$ ~/tt
----- Bug String  -----
status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory|SIGABRT|THD::~THD|THD::~THD|do_handle_one_connection|handle_one_connection

Comment by Roel Van de Paar [ 2022-09-10 ]

Additional testcase

CREATE TABLE t (a INT,b INT) ROW_FORMAT=REDUNDANT ENGINE=InnoDB;
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
SHUTDOWN;

10.10.0 7a41e4fbc62c5e917d9cb4dc045e21c983d4e73f

Warning: Memory not freed: 16448

Comment by Roel Van de Paar [ 2022-09-28 ]

CREATE TABLE t (a INT KEY,message CHAR,FULLTEXT (message)) COMMENT='';
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
SHUTDOWN;

10.11.0 6ebdd3013a18b01dbecec76b870810329eb76586 (Optimized)

2022-09-28 18:02:23 0 [Note] /test/MD190922-mariadb-10.11.0-linux-x86_64-opt/bin/mysqld: Shutdown complete
Warning: Memory not freed: 16496

Comment by Roel Van de Paar [ 2023-01-09 ]

Additional testcase

CREATE TABLE t (c INT,d DATE) PARTITION BY RANGE (YEAR (d)) SUBPARTITION BY HASH (TO_DAYS (d)) (PARTITION p0 VALUES LESS THAN (1) (SUBPARTITION s0,SUBPARTITION s),PARTITION p VALUES LESS THAN MAXVALUE (SUBPARTITION s4,SUBPARTITION s5));
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
SHUTDOWN;

Comment by Roel Van de Paar [ 2023-03-20 ]

11.0.1 f2dc4d4c10ac36a73b5c1eb765352d3aee808d66 (Optimized)

Warning: Memory not freed: 16808

With this testcase

CREATE TABLE t (a INT KEY,b INT,FOREIGN KEY(b) REFERENCES t (a)) ENGINE=InnoDB ROW_FORMAT=REDUNDANT;
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
SHUTDOWN;

Comment by Oleksandr Byelkin [ 2023-09-25 ]

I can not repeat it

CREATE TABLE t (c1 INT, c2 DATE) TABLESPACE t STORAGE MEMORY;
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2';
main.test 'innodb'                       [ fail ]
        Test ended at 2023-09-25 13:54:05
 
CURRENT_TEST: main.test
mysqltest: At line 4: query 'PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS d1,d AS d2'' failed: 1222: The used SELECT statements have a different number of columns

Comment by Oleksandr Byelkin [ 2023-09-25 ]

the test sacase from the first comet also returns with an error

Comment by Oleksandr Byelkin [ 2023-09-25 ]

Roel if error expected there is --error construction in the test

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