[MDEV-22035] Memory leak in main.mysqltest Created: 2020-03-25  Updated: 2020-04-01  Resolved: 2020-03-25

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.2, 10.5
Fix Version/s: 10.2.32, 10.3.23, 10.4.13, 10.5.2

Type: Bug Priority: Major
Reporter: Marko Mäkelä Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: ASAN

Issue Links:
Relates

 Description   

I debugged the main.mysqltest failure that reliably occurs on kvm-asan. It looks like a bug in GCC 5.4.0’s ASAN implementation to me:

10.5 6fb59d525b7047c82e350d2b721bffc50431eb12

mysqltest: At line 1: Error parsing replace_regex "a"
 
Program received signal SIGABRT, Aborted.
0x00007ffff534a428 in raise () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) bt
#0  0x00007ffff534a428 in raise () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ffff534c02a in abort () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x00007ffff6f17dc9 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#3  0x00007ffff6f0a769 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#4  0x00007ffff6f0f5d2 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#5  0x00007ffff6f17558 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#6  0x00007ffff6f18a38 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#7  0x00007ffff6f18bbe in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#8  0x00007ffff6f225a6 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#9  0x00007ffff534f36a in __cxa_finalize ()
   from /lib/x86_64-linux-gnu/libc.so.6
#10 0x00007ffff6e875a3 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#11 0x00007ffffffbdae0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Even if I set a breakpoint on __cxa_finalize () and rerun, I will not get more information. There is only that one thread:

Starting program: /home/buildbot/server/build/client/mysqltest --defaults-file=/home/buildbot/server/build/mysql-test/var/my.cnf --silent --tmpdir=/home/buildbot/server/build/mysql-test/var/tmp --character-sets-dir=/home/buildbot/server/sql/share/charsets --logdir=/home/buildbot/server/build/mysql-test/var/log --database=test --timer-file=/home/buildbot/server/build/mysql-test/var/log/timer < foo
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
mysqltest: At line 1: Error parsing replace_regex "a"
 
Breakpoint 1, 0x00007ffff534f2d0 in __cxa_finalize ()
   from /lib/x86_64-linux-gnu/libc.so.6
(gdb) thr a a bt
 
Thread 1 (Thread 0x7ffff7fe0780 (LWP 21098)):
#0  0x00007ffff534f2d0 in __cxa_finalize ()
   from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ffff6e875a3 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.2
#2  0x00007ffffffbdae0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Test setup:

cd build/mysql-test
echo 'echo $MYSQL_TEST;' > ../../mysql-test/main/m.test
echo --replace_regex a > foo
./mtr --manual-gdb main.m
gdb -cd /home/buildbot/server/mysql-test -x /home/buildbot/server/build/mysql-test/var/tmp/gdbinit.mysqld.1 /home/buildbot/server/build/sql/mysqld

Then, in gdb, type

run
# (hit ctrl-z to suspend the server process)
detach
quit

and finally start the mysqltest client in another gdb:

run /home/buildbot/server/build/client/mysqltest --defaults-file=/home/buildbot/server/build/mysql-test/var/my.cnf --silent --tmpdir=/home/buildbot/server/build/mysql-test/var/tmp --character-sets-dir=/home/buildbot/server/sql/share/charsets --logdir=/home/buildbot/server/build/mysql-test/var/log --database=test --timer-file=/home/buildbot/server/build/mysql-test/var/log/timer < foo

The arguments are from the $MYSQL_TEST, except for the < foo redirection.

Note: If I try to invoke ./mtr main.n on the following n.test file directly, then there is no SIGABRT reported:

--replace_regex a

It will only report a failure like this:

main.n                                   [ fail ]
        Test ended at 2020-03-21 08:19:40
 
CURRENT_TEST: main.n
mysqltest: At line 1: Error parsing replace_regex "a"

There is nothing in any log files either:

grep -ri sanitizer var

var/tmp/check-mysqld_1.result:HAVE_SANITIZER	ASAN
var/tmp/check-mysqld_1.log:HAVE_SANITIZER	ASAN
var/log/main.n/tmp/check-mysqld_1.result:HAVE_SANITIZER	ASAN
var/log/main.n/tmp/check-mysqld_1.log:HAVE_SANITIZER	ASAN

On my local system, typically using clang version 7, 8, 9, or 10, I have experienced a hang of main.mysqltest since June 2019, on 10.5 and possibly also on 10.4. I finally decided to debug it, and it looks like it could be the same problem. Only, for some reason, the mysqltest process is hanging instead of crashing:

10.5 9a7d284e202d8862a7b34aaf2253d4627177a90e

gdb /dev/shm/10.5a/client/mysqltest
GNU gdb (Debian 9.1-2) 9.1
Copyright (C) 2020 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.
 
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /dev/shm/10.5a/client/mysqltest...
(gdb) set env ASAN_OPTIONS=abort_on_error=1
(gdb) run --defaults-file=/dev/shm/10.5a/mysql-test/var/my.cnf --silent --tmpdir=/dev/shm/10.5a/mysql-test/var/tmp --character-sets-dir=/mariadb/10.5m/sql/share/charsets --logdir=/dev/shm/10.5a/mysql-test/var/log --database=test --timer-file=/dev/shm/10.5a/mysql-test/var/log/timer < /mariadb/10.5m/mysql-test/main/n.test 
Starting program: /dev/shm/10.5a/client/mysqltest --defaults-file=/dev/shm/10.5a/mysql-test/var/my.cnf --silent --tmpdir=/dev/shm/10.5a/mysql-test/var/tmp --character-sets-dir=/mariadb/10.5m/sql/share/charsets --logdir=/dev/shm/10.5a/mysql-test/var/log --database=test --timer-file=/dev/shm/10.5a/mysql-test/var/log/timer < /mariadb/10.5m/mysql-test/main/n.test
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
mysqltest: At line 1: Error parsing replace_regex "a"
 
Program received signal SIGABRT, Aborted.
__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: Tiedostoa tai hakemistoa ei ole.
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffff770f55b in __GI_abort () at abort.c:79
#2  0x00000000004d1f37 in __sanitizer::Abort() ()
    at /mariadb/10.5m/client/mysqltest.cc:829
#3  0x00000000004d0961 in __sanitizer::Die() ()
    at /mariadb/10.5m/client/mysqltest.cc:829
#4  0x00000000004db3d4 in __lsan::CheckForLeaks() ()
    at /mariadb/10.5m/client/mysqltest.cc:829
#5  0x00000000004db0a2 in __lsan::DoLeakCheck() ()
    at /mariadb/10.5m/client/mysqltest.cc:829
#6  0x00007ffff7727e27 in __run_exit_handlers (status=1, 
    listp=0x7ffff78a6718 <__exit_funcs>, 
    run_list_atexit=run_list_atexit@entry=true, run_dtors=run_dtors@entry=true)
    at exit.c:108
#7  0x00007ffff7727fda in __GI_exit (status=<optimized out>) at exit.c:139
#8  0x00000000004ed2dd in cleanup_and_exit (exit_code=1)
    at /mariadb/10.5m/client/mysqltest.cc:1567
#9  0x00000000004ed0c7 in really_die (msg=<optimized out>)
    at /mariadb/10.5m/client/mysqltest.cc:1276
#10 0x00000000004eae92 in die (fmt=<optimized out>)
    at /mariadb/10.5m/client/mysqltest.cc:1615
#11 0x000000000051f88a in append_replace_regex (expr=<optimized out>, 
    expr_end=<optimized out>, res=<optimized out>, buf_p=<optimized out>)
    at /mariadb/10.5m/client/mysqltest.cc:10269
#12 0x000000000051a268 in init_replace_regex (expr=0x604000000e36 "a")
    at /mariadb/10.5m/client/mysqltest.cc:10188
#13 do_get_replace_regex (command=0x612000000058)
    at /mariadb/10.5m/client/mysqltest.cc:10349
#14 0x0000000000517cca in main (argc=<optimized out>, argv=0x7fffffffdfe0)
    at /mariadb/10.5m/client/mysqltest.cc:9633

This particular one was built cmake -DWITH_PCRE2=bundled. I have seen (but not debugged) the hang also with the system-provided library.

Workaround: Set ASAN_OPTIONS=detect_leaks=0 for the mysqltest invocation, and it will not crash or hang.
I can run the entire test without problems, using

ASAN_OPTIONS=detect_leaks=0 ./mtr main.mysqltest



 Comments   
Comment by Marko Mäkelä [ 2020-03-25 ]

I forgot that LeakSanitizer does not work inside gdb. If I manually invoke the client, then I can get the log to a separate file:

ASAN_OPTIONS=log_path=/dev/shm/asan /dev/shm/10.5a/client/mysqltest --defaults-file=/dev/shm/10.5a/mysql-test/var/my.cnf --silent --tmpdir=/dev/shm/10.5a/mysql-test/var/tmp --character-sets-dir=/mariadb/10.5m/sql/share/charsets --logdir=/dev/shm/10.5a/mysql-test/var/log --database=test --timer-file=/dev/shm/10.5a/mysql-test/var/log/timer < /mariadb/10.5m/mysql-test/main/n.test 

10.5 9a7d284e202d8862a7b34aaf2253d4627177a90e

=================================================================
==1219775==ERROR: LeakSanitizer: detected memory leaks
 
Direct leak of 3096 byte(s) in 1 object(s) allocated from:
    #0 0x4b42fd in malloc (/dev/shm/10.5a/client/mariadb-test+0x4b42fd)
    #1 0x5e50bc in my_malloc /mariadb/10.5m/mysys/my_malloc.c:88:29
    #2 0x5afda0 in init_dynamic_array2 /mariadb/10.5m/mysys/array.c:71:33
    #3 0x51a232 in init_replace_regex(char*) /mariadb/10.5m/client/mysqltest.cc:10184:3
    #4 0x51a232 in do_get_replace_regex(st_command*) /mariadb/10.5m/client/mysqltest.cc:10349:45
    #5 0x517cc9 in main /mariadb/10.5m/client/mysqltest.cc:9633:9
    #6 0x7fcf70794e0a in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x26e0a)
 
SUMMARY: AddressSanitizer: 3096 byte(s) leaked in 1 allocation(s).

The fix was simple. I have no idea why this is not being reported for older branches than 10.5, even though the leak seems to be there.

diff --git a/client/mysqltest.cc b/client/mysqltest.cc
index 3c878d4cb97..254020ba124 100644
--- a/client/mysqltest.cc
+++ b/client/mysqltest.cc
@@ -10265,6 +10265,7 @@ void append_replace_regex(char* expr, char *expr_end, struct st_replace_regex* r
   return;
 
 err:
+  my_free(res->regex_arr.buffer);
   my_free(res);
   die("Error parsing replace_regex \"%s\"", expr);
 }

Comment by Marko Mäkelä [ 2020-04-01 ]

This started to occur on 10.2 as well, so I ported the fix there.

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