[MDEV-32223] Memory leak showed in MDEV-6146 test suite Created: 2023-09-21  Updated: 2023-10-19  Resolved: 2023-09-28

Status: Closed
Project: MariaDB Server
Component/s: Full-text Search
Fix Version/s: 10.4.32, 10.5.23, 10.6.16, 10.10.7, 10.11.6, 11.0.4, 11.1.3, 11.2.2

Type: Task Priority: Critical
Reporter: Oleksandr Byelkin Assignee: Oleksandr Byelkin
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-14959 Control over memory allocated for SP/PS Stalled

 Description   

test suite of MDEV-6146 fails with -DWITH_PROTECT_STATEMENT_MEMROOT:BOOL=ON

sanja@SanjaLaptop:~/maria/git/10.4/mysql-test$ ./mysql-test-run --ps-protocol --mem main.fulltext
Logging: ./mysql-test-run  --ps-protocol --mem main.fulltext
VS config: 
vardir: /home/sanja/maria/git/10.4/mysql-test/var
Checking leftover processes...
 - found old pid 1042114 in 'mysqld.1.pid', killing it...
   process did not exist!
Removing old var directory...
Creating var directory '/home/sanja/maria/git/10.4/mysql-test/var'...
 - symlinking 'var' to '/dev/shm/var_auto_6Wdz'
Checking supported features...
MariaDB Version 10.4.32-MariaDB-debug
 - SSL connections supported
 - binaries are debug compiled
 - binaries built with wsrep patch
Collecting tests...
Installing system database...
 
==============================================================================
 
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
 
worker[01] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
main.fulltext                            [ fail ]
        Test ended at 2023-09-21 12:55:54
 
CURRENT_TEST: main.fulltext
mysqltest: At line 684: query 'SELECT * FROM t1 WHERE MATCH (txt1,txt2) AGAINST ('ööö1' IN BOOLEAN MODE)' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
SELECT * FROM t1 WHERE MATCH (id2, uid, txt) AGAINST ('txt1' IN BOOLEAN MODE);
txt	uid	id2
txt1	1234	5678
SELECT * FROM t1 WHERE MATCH (id2, uid, txt) AGAINST ('1234' IN BOOLEAN MODE);
txt	uid	id2
txt1	1234	5678
SELECT * FROM t1 WHERE MATCH (id2, uid, txt) AGAINST ('5678' IN BOOLEAN MODE);
txt	uid	id2
txt1	1234	5678
DROP TABLE t1;
CREATE TABLE t1 (
txt1 text COLLATE utf8_unicode_ci NOT NULL,
txt2 text COLLATE latin1_swedish_ci NOT NULL
) ENGINE=MyISAM DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;
INSERT INTO t1 VALUES ('nnn1 x1 y1 ööö1','mmm1 ùùù1');
INSERT INTO t1 VALUES ('nnn2 x2 y2 ööö2','mmm2 ùùù2');
INSERT INTO t1 VALUES ('nnn3 x3 y3 ööö3','mmm3 ùùù3');
INSERT INTO t1 VALUES ('nnn4 x4 y4 ööö4','mmm4 ùùù4');
INSERT INTO t1 VALUES ('nnn5 x5 y5 ööö5','mmm5 	');
SELECT * FROM t1 WHERE MATCH (txt1,txt2) AGAINST ('ööö1' IN BOOLEAN MODE);
 
More results from queries before failure can be found in /home/sanja/maria/git/10.4/mysql-test/var/log/fulltext.log
 
 
Server [mysqld.1 - pid: 1042182, winpid: 1042182, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
$ /home/sanja/maria/git/10.4/sql/mysqld --defaults-group-suffix=.1 --defaults-file=/home/sanja/maria/git/10.4/mysql-test/var/my.cnf --log-output=file --core-file --loose-debug-sync-timeout=300
2023-09-21 12:55:53 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32198)
2023-09-21 12:55:53 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2023-09-21 12:55:53 0 [Note] Starting MariaDB 10.4.32-MariaDB-debug-log source revision 5a7bcf16940967e5f78d48366216f07d2c0e5284 as process 1042183
2023-09-21 12:55:53 0 [Note] Plugin 'partition' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'SEQUENCE' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'InnoDB' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_LOCKS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_CMPMEM' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_CMP' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'FEEDBACK' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'user_variables' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_TRX' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_METRICS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2023-09-21 12:55:53 0 [Note] Plugin 'unix_socket' is disabled.
2023-09-21 12:55:53 0 [Warning] /home/sanja/maria/git/10.4/sql/mysqld: unknown option '--loose-pam-debug'
2023-09-21 12:55:53 0 [Warning] /home/sanja/maria/git/10.4/sql/mysqld: unknown option '--loose-aria'
2023-09-21 12:55:53 0 [Note] Server socket created on IP: '127.0.0.1'.
2023-09-21 12:55:53 0 [Note] Reading of all Master_info entries succeeded
2023-09-21 12:55:53 0 [Note] Added new Master_info '' to hash table
2023-09-21 12:55:53 0 [Note] /home/sanja/maria/git/10.4/sql/mysqld: ready for connections.
Version: '10.4.32-MariaDB-debug-log'  socket: '/home/sanja/maria/git/10.4/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
mysqld: /home/sanja/maria/git/10.4/mysys/my_alloc.c:225: alloc_root: Assertion `mem_root->read_only == 0' failed.
230921 12:55:53 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
Server version: 10.4.32-MariaDB-debug-log source revision: 5a7bcf16940967e5f78d48366216f07d2c0e5284
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=153
thread_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63666 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f86f4000da0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x7f870584cce8 thread_stack 0x49000
mysys/stacktrace.c:174(my_print_stacktrace)[0x560d4b8db6b7]
sql/signal_handler.cc:238(handle_fatal_signal)[0x560d4af2e204]
libc_sigaction.c:0(__restore_rt)[0x7f870b63c4b0]
nptl/pthread_kill.c:44(__pthread_kill_implementation)[0x7f870b690ffb]
posix/raise.c:27(__GI_raise)[0x7f870b63c406]
stdlib/abort.c:81(__GI_abort)[0x7f870b62287c]
intl/loadmsgcat.c:1177(_nl_load_domain)[0x7f870b62279b]
/lib/x86_64-linux-gnu/libc.so.6(+0x33b86)[0x7f870b633b86]
mysys/my_alloc.c:228(alloc_root)[0x560d4b8c64de]
sql/item.h:740(Item::operator new(unsigned long, st_mem_root*))[0x560d4aa7403c]
sql/item.cc:2592(Type_std_attributes::agg_item_set_converter(DTCollation const&, char const*, Item**, unsigned int, unsigned int, int))[0x560d4af59fb5]
sql/sql_type.h:3108(Type_std_attributes::agg_arg_charsets(DTCollation&, char const*, Item**, unsigned int, unsigned int, int))[0x560d4ae2221d]
sql/sql_type.h:3156(Type_std_attributes::agg_arg_charsets_for_comparison(DTCollation&, char const*, Item**, unsigned int, int))[0x560d4ae222d1]
sql/item.h:5253(Item_func_or_sum::agg_arg_charsets_for_comparison(DTCollation&, Item**, unsigned int, int))[0x560d4ae27201]
sql/item_func.cc:6150(Item_func_match::fix_fields(THD*, Item**))[0x560d4afe386a]
sql/item.h:966(Item::fix_fields_if_needed(THD*, Item**))[0x560d4aa82ddd]
sql/item.h:970(Item::fix_fields_if_needed_for_scalar(THD*, Item**))[0x560d4aa82e17]
sql/item.h:975(Item::fix_fields_if_needed_for_bool(THD*, Item**))[0x560d4ab15337]
sql/sql_base.cc:8545(setup_conds(THD*, TABLE_LIST*, List<TABLE_LIST>&, Item**))[0x560d4ab115e5]
sql/sql_select.cc:744(setup_without_group(THD*, Bounds_checked_array<Item*>, TABLE_LIST*, List<TABLE_LIST>&, List<Item>&, List<Item>&, Item**, st_order*, st_order*, List<Window_spec>&, List<Item_window_func>&, bool*))[0x560d4abff2df]
sql/sql_select.cc:1335(JOIN::prepare(TABLE_LIST*, unsigned int, Item*, unsigned int, st_order*, bool, st_order*, Item*, st_order*, st_select_lex*, st_select_lex_unit*))[0x560d4ac02827]
sql/sql_select.cc:4789(mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*))[0x560d4ac0fec1]
sql/sql_select.cc:442(handle_select(THD*, LEX*, select_result*, unsigned long))[0x560d4abfe681]
sql/sql_parse.cc:6475(execute_sqlcom_select(THD*, TABLE_LIST*))[0x560d4abbe030]
sql/sql_parse.cc:3978(mysql_execute_command(THD*))[0x560d4abb44ee]
sql/sql_prepare.cc:5068(Prepared_statement::execute(String*, bool))[0x560d4abe6961]
sql/sql_prepare.cc:4515(Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*))[0x560d4abe4a2f]
sql/sql_prepare.cc:3479(mysql_stmt_execute_common(THD*, unsigned long, unsigned char*, unsigned char*, unsigned long, bool, bool))[0x560d4abe1cb2]
sql/sql_prepare.cc:3264(mysqld_stmt_execute(THD*, char*, unsigned int))[0x560d4abe1547]
sql/sql_parse.cc:1783(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x560d4abad4b2]
sql/sql_parse.cc:1378(do_command(THD*))[0x560d4abac1c1]
sql/sql_connect.cc:1420(do_handle_one_connection(CONNECT*))[0x560d4ad5ca06]
sql/sql_connect.cc:1325(handle_one_connection)[0x560d4ad5c753]
perfschema/pfs.cc:1871(pfs_spawn_thread)[0x560d4b3184d6]
nptl/pthread_create.c:444(start_thread)[0x7f870b68f18a]
x86_64/clone3.S:83(clone3)[0x7f870b71dbd0]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7f86f40d7398): SELECT * FROM t1 WHERE MATCH (txt1,txt2) AGAINST ('ööö1' IN BOOLEAN MODE)
 
Connection ID (thread ID): 4
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on
 
The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
information that should help you find out what is causing the crash.
Writing a core file...
Working directory at /dev/shm/var_auto_6Wdz/mysqld.1/data
Resource Limits:
Limit                     Soft Limit           Hard Limit           Units     
Max cpu time              unlimited            unlimited            seconds   
Max file size             unlimited            unlimited            bytes     
Max data size             unlimited            unlimited            bytes     
Max stack size            8388608              unlimited            bytes     
Max core file size        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             255556               255556               processes 
Max open files            1024                 1024                 files     
Max locked memory         8390840320           8390840320           bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       255556               255556               signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
Core pattern: |/usr/share/apport/apport -p%p -s%s -c%c -d%d -P%P -u%u -g%g -- %E
 
Kernel version: Linux version 6.2.0-33-generic (buildd@lcy02-amd64-050) (x86_64-linux-gnu-gcc-12 (Ubuntu 12.3.0-1ubuntu1~23.04) 12.3.0, GNU ld (GNU Binutils for Ubuntu) 2.40) #33-Ubuntu SMP PREEMPT_DYNAMIC Tue Sep  5 14:49:19 UTC 2023
 
----------SERVER LOG END-------------
 
 
 - saving '/home/sanja/maria/git/10.4/mysql-test/var/log/main.fulltext/' to '/home/sanja/maria/git/10.4/mysql-test/var/log/main.fulltext/'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 3 seconds executing testcases
 
Failure: Failed 1/1 tests, 0.00% were successful.
 
Failing test(s): main.fulltext



 Comments   
Comment by Oleksandr Byelkin [ 2023-09-21 ]

commit c9f19a850629f21c479e42083df00c9f208cd62a (HEAD -> bb-10.4-MDEV-32223, origin/bb-10.4-MDEV-32223)
Author: Oleksandr Byelkin <sanja@mariadb.com>
Date:   Thu Sep 21 13:01:48 2023 +0200
 
    MDEV-32223 Memory leak showed in MDEV-6146 test suite
    
    Fix propagate_equal_fields to avoid removing Item_direct_ref_to_item from the Item tree and so reallocating it.
    
    Fix Item_func_match to avoid removing Item_direct_ref_to_item from item tree via real_item() call.

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