[MDEV-10455] libmariadbclient18 + MySQL-python leaks memory on failed connections Created: 2016-07-27  Updated: 2016-08-12  Resolved: 2016-08-12

Status: Closed
Project: MariaDB Server
Component/s: Scripts & Clients
Affects Version/s: 10.0, 10.1
Fix Version/s: 10.1.17, 10.0.27

Type: Bug Priority: Major
Reporter: Andrew Garner Assignee: Oleksandr Byelkin
Resolution: Fixed Votes: 0
Labels: None
Environment:

Debian 8


Issue Links:
Relates
relates to MDEV-10546 Make unit tests run with valgrind Open
relates to MDEV-10546 Make unit tests run with valgrind Open

 Description   

When MySQLdb (python-mysqldb) uses the MariaDB libmysqlclient.so.18 libraries, it seems to leak memory with each failed connection. A simple contrived loop (w/ mariadb stopped, generating client 2003 errors) leads to a few GB RSS for the associated python process in a few seconds when using the MariaDB 10.1 client packages:

#!/usr/bin/env python
 
import resource
import time
 
import MySQLdb
 
print("Client version: %s" % MySQLdb.get_client_info())
 
max_allowed_rss = 512*1024
failed_connects = 0
initial_rss = resource.getrusage(resource.RUSAGE_SELF).ru_maxrss
 
for _ in xrange(50000):
    try:
        MySQLdb.connect(user='root', host='127.0.0.1')
    except MySQLdb.Error:
        failed_connects += 1
 
print("maxrss initial was: %sKB, final is %sKB; %.2fMiB change after %d failed connections." %
        (
        initial_rss,
        resource.getrusage(resource.RUSAGE_SELF).ru_maxrss,
        (resource.getrusage(resource.RUSAGE_SELF).ru_maxrss - initial_rss) / 1024.0,
        failed_connects
        )
    )

The output of running this is as follows:

$ apt-get install libmysqlclient18=5.5.50-0+deb8u1
$ python mdev10455_mysqldb_memleak.py
Client version: 5.5.50
maxrss initial was: 8364KB, final is 10044KB; 1.64MiB change after 50000 failed connections.
 
$ apt-get install libmysqlclient18=5.6.30-1~bpo8+1
$ python mdev10455_mysqldb_memleak.py
Client version: 5.6.30
maxrss initial was: 8536KB, final is 10216KB; 1.64MiB change after 50000 failed connections.
 
$ apt-get install libmysqlclient18=10.1.16+maria-1~jessie
$ python mdev10455_mysqldb_memleak.py
Client version: 10.1.16-MariaDB
maxrss initial was: 9272KB, final is 437896KB; 418.58MiB change after 50000 failed connections.

Removing libmariadbclient18 and reverting to the libmysqlclient18 provided by either MySQL 5.5 (5.5.50-0+deb8u1) (debian/jessie main) or MySQL 5.6 (5.6.30-1~bpo8+1 from jessie-backports), the memory leak goes away and memory use stays constant over time.

I see MySQL-python does not call mysql_close() on a failed connection which seems to resolve this behavior with MariaDB - so perhaps this is an incorrect API usage bug. However the MariaDB behavior does seem to differ from the MySQL (5.5.50, 5.6.30) behavior, so I am opening this issue.



 Comments   
Comment by Elena Stepanova [ 2016-07-29 ]

Thanks for the report.

It started happening with the following revision in 10.0.5:

commit b803b46dac40d2417e41c778938d97951ce4ec88
Author: unknown <sanja@askmonty.org>
Date:   Thu Oct 3 18:00:44 2013 +0300
 
    Client attributes

Comment by Oleksandr Byelkin [ 2016-08-10 ]

pure C test do not leak memory, so probably python uses some preparation and then do not clean...

Comment by Oleksandr Byelkin [ 2016-08-10 ]

and BTW I did not call mysql_close()... but also did not init a new connection... actually without mysql_close() it can just leak allocated MYSQL object (who knows what that python id doing and how call mysql_init())...

Comment by Oleksandr Byelkin [ 2016-08-10 ]

I do not see obvious flows in client connection attributes initialization. So it is probably how python uses the clientlibrary. Which is a bit difficult for me to test because I can't repeat it with build libraries (it looks like python uses something different then LD_LIBRARY_PATH and LD_PRELOAD to get the library).

Comment by Oleksandr Byelkin [ 2016-08-10 ]

BTW that libmariadbclient18 is libmysqld supplied with server or connectors-C? Is it debian?

Comment by Andrew Garner [ 2016-08-10 ]

This libmariadbclient18 is libmysqld supplied I believe - not the connector/C variant. I see Debian ships what I think is an older version of the MariaDB Connector/C (libmariadb2 -> v2.0.0) and this does not exhibit the same "leaking" behavior (using the naive python script above):

# apt-get install libmariadb2
# LD_PRELOAD=/usr/lib/x86_64-linux-gnu/libmariadb.so.2 python mdev10455_mysqldb_memleak.py
Client version: 5.5.0
maxrss initial was: 9184KB, final is 10868KB; 1.64MiB change after 50000 failed connections.

Simply removing LD_PRELOAD shows different behavior:

# python mdev10455_mysqldb_memleak.py
Client version: 10.1.16-MariaDB
maxrss initial was: 9256KB, final is 437884KB; 418.58MiB change after 50000 failed connections.

Comment by Andrew Garner [ 2016-08-10 ]

FWIW, the following "pure C" program exhibits the same behavior. This should be similar to what MySQL-python does from reading the code. As I understand it from my reading of the source, MySQL-python allocates a struct with a "MYSQL connection" member, calls mysql_init a series of mysql_option calls and mysql_real_connect. If mysql_real_connect fails, mysql_errno / mysql_error are called, but mysql_close is not.

#include <stdio.h>
#include <sys/time.h>
#include <sys/resource.h>
 
#include "mysql.h"
#include "mysqld_error.h"
 
int main(int argc, char **argv) {
	int i = 0xdeadbeef;
	int connect_errors = 0, closed_connections = 0;
	struct rusage usage;
	for(i = 0;i < 50000;i++) {
		MYSQL connection, *c = NULL;
 
		c = mysql_init(&connection);
		c = mysql_real_connect(&connection, "localhost", "invalid", "invalid", "", 3306, "/var/run/mysqld/bad.sock", 0);
		if (c == NULL) {
			/* fprintf(stderr, "[%d] %s\n", mysql_errno(&connection), mysql_error(&connection)); */
			connect_errors++;
		}
		/* explicitly skip mysql_close */
		if (argc > 1) {
			mysql_close(&connection);
			closed_connections++;
		}
	}
	fprintf(stderr, "%d total connect errors (%d closed connections)\n", connect_errors, closed_connections);
 
	if(getrusage(RUSAGE_SELF, &usage) == 0) {
		fprintf(stderr, "max_rss: %d\n", usage.ru_maxrss);
	}
}

Here's some output from my environment - still using Debian8 w/ libmariadbclient18 + libmariadbclient-dev from 10.1.16~maria-1~jessie packages.

$ gcc mdev10455.c $(mysql_config --include --libs_r) -o mdev10455_memleak
 
$ ldd mdev10455_memleak  | grep libmysqlclient
	libmysqlclient.so.18 => /usr/lib/x86_64-linux-gnu/libmysqlclient.so.18 (0x00007fa87e66a000)
 
 
# Mimic MySQL-python
$ ./mdev10455_memleak
50000 total connect errors (0 closed connections)
max_rss: 259172
 
# Test with calling mysql_close after each failure attempt.
$ ./mdev10455_memleak  --close
50000 total connect errors (50000 closed connections)
max_rss: 4696
 
# Test by forcing MariaDB Connector/C without closing connections
$ LD_PRELOAD=/usr/lib/x86_64-linux-gnu/libmariadb.so.2 ./mdev10455_memleak
50000 total connect errors (0 closed connections)
max_rss: 4236
 
# Test by forcing MariaDB Connector/C with closing connections
$ LD_PRELOAD=/usr/lib/x86_64-linux-gnu/libmariadb.so.2 ./mdev10455_memleak  --close
50000 total connect errors (50000 closed connections)
max_rss: 4180
 
# Test by installing mysql-5.5.50 libmysqlclient
$ sudo apt-get install libmysqlclient18=5.5.50-0+deb8u1
$ ./mdev10455_memleak
50000 total connect errors (0 closed connections)
max_rss: 4520

I also ran valgrind output here, if it's helpful at all and this does seem to indicate a leak:

$ valgrind --tool=memcheck --leak-check=full ./mdev10455_memleak
==984== Memcheck, a memory error detector
==984== Copyright (C) 2002-2013, and GNU GPL'd, by Julian Seward et al.
==984== Using Valgrind-3.10.0 and LibVEX; rerun with -h for copyright info
==984== Command: ./mdev10455_memleak
==984==
50000 total connect errors (0 closed connections)
max_rss: 488972
==984==
==984== HEAP SUMMARY:
==984==     in use at exit: 434,000,392 bytes in 350,003 blocks
==984==   total heap usage: 450,056 allocs, 100,053 frees, 1,278,805,913 bytes allocated
==984==
==984== 32 bytes in 1 blocks are possibly lost in loss record 1 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E9ABD3: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E5AC84: mysql_server_init (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E614D6: mysql_init (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400842: main (in /root/mdev10455_memleak)
==984==
==984== 160 bytes in 1 blocks are possibly lost in loss record 7 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E99FD9: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E6CF1D: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E5AC8B: mysql_server_init (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E614D6: mysql_init (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400842: main (in /root/mdev10455_memleak)
==984==
==984== 2,352 bytes in 14 blocks are possibly lost in loss record 10 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63AF8: mysql_options (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63F2A: mysql_real_connect (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400877: main (in /root/mdev10455_memleak)
==984==
==984== 22,456 bytes in 401 blocks are possibly lost in loss record 12 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E99D84: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63D10: mysql_options4 (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E64057: mysql_real_connect (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400877: main (in /root/mdev10455_memleak)
==984==
==984== 25,600 bytes in 400 blocks are possibly lost in loss record 13 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E99D84: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63D10: mysql_options4 (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63FD9: mysql_real_connect (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400877: main (in /root/mdev10455_memleak)
==984==
==984== 25,664 bytes in 401 blocks are possibly lost in loss record 14 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E99D84: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63D10: mysql_options4 (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E64015: mysql_real_connect (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400877: main (in /root/mdev10455_memleak)
==984==
==984== 28,944 bytes in 402 blocks are possibly lost in loss record 15 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E99D84: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63D10: mysql_options4 (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63FBB: mysql_real_connect (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400877: main (in /root/mdev10455_memleak)
==984==
==984== 29,016 bytes in 403 blocks are possibly lost in loss record 16 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E99D84: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63D10: mysql_options4 (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63FF7: mysql_real_connect (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400877: main (in /root/mdev10455_memleak)
==984==
==984== 3,232,680 bytes in 395 blocks are possibly lost in loss record 20 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E930EC: alloc_dynamic (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E97FC8: ??? (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63D77: mysql_options4 (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63FBB: mysql_real_connect (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400877: main (in /root/mdev10455_memleak)
==984==
==984== 430,615,680 (8,396,808 direct, 422,218,872 indirect) bytes in 49,981 blocks are definitely lost in loss record 24 of 24
==984==    at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==984==    by 0x4E9EB49: my_malloc (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63AF8: mysql_options (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x4E63F2A: mysql_real_connect (in /usr/lib/libmysqlclient.so.18.0.0)
==984==    by 0x400877: main (in /root/mdev10455_memleak)
==984==
==984== LEAK SUMMARY:
==984==    definitely lost: 8,396,808 bytes in 49,981 blocks
==984==    indirectly lost: 422,218,872 bytes in 297,590 blocks
==984==      possibly lost: 3,366,904 bytes in 2,418 blocks
==984==    still reachable: 17,808 bytes in 14 blocks
==984==         suppressed: 0 bytes in 0 blocks
==984== Reachable blocks (those to which a pointer was found) are not shown.
==984== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==984==
==984== For counts of detected and suppressed errors, rerun with: -v
==984== ERROR SUMMARY: 10 errors from 10 contexts (suppressed: 0 from 0)

And again with libmysqlclient18_5.5.50-0+deb8u1_amd64.deb

$ valgrind --tool=memcheck --leak-check=full ./mdev10455_memleak
==1143== Memcheck, a memory error detector
==1143== Copyright (C) 2002-2013, and GNU GPL'd, by Julian Seward et al.
==1143== Using Valgrind-3.10.0 and LibVEX; rerun with -h for copyright info
==1143== Command: ./mdev10455_memleak
==1143==
50000 total connect errors (0 closed connections)
max_rss: 63848
==1143==
==1143== HEAP SUMMARY:
==1143==     in use at exit: 360 bytes in 3 blocks
==1143==   total heap usage: 100,058 allocs, 100,055 frees, 843,606,225 bytes allocated
==1143==
==1143== LEAK SUMMARY:
==1143==    definitely lost: 0 bytes in 0 blocks
==1143==    indirectly lost: 0 bytes in 0 blocks
==1143==      possibly lost: 0 bytes in 0 blocks
==1143==    still reachable: 360 bytes in 3 blocks
==1143==         suppressed: 0 bytes in 0 blocks
==1143== Reachable blocks (those to which a pointer was found) are not shown.
==1143== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==1143==
==1143== For counts of detected and suppressed errors, rerun with: -v
==1143== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

Comment by Andrew Garner [ 2016-08-10 ]

Also, as I follow my curiosity, this issue also seems to affect other libmysqlclient based connectors which seem to assume they either need not or should not call mysql_close after mysql_real_connect fails.

For another example, see this trivial perl program using DBD-mysql.

#!/usr/bin/perl
 
use DBI;
 
for(my $i = 0; $i < 50000;$i++) {
	my $dbh = DBI->connect("DBI:mysql:database=test;host=localhost", "user", "pw", { 'PrintError' => 0 });
}

valgrind shows a similar leak report here - which goes away with either MariaDB Connector/C or the MySQL 5.5 / 5.6 libmysqlclient libraries.

Comment by Oleksandr Byelkin [ 2016-08-10 ]

Thank you, now it is repeatable.

Comment by Oleksandr Byelkin [ 2016-08-11 ]

It was not implemented CLIENT_REMEMBER_OPTIONS.

Comment by Oleksandr Byelkin [ 2016-08-11 ]

support added, problem fixed, now trying to put the test into regression test test suite (if possible)...

Comment by Oleksandr Byelkin [ 2016-08-11 ]

revision-id: 66ac894c40ad089175aaf6d4922f7250c23b9b3d (mariadb-10.0.26-17-g66ac894)
parent(s): b5fb2a685b6ec67d37033b020a8145d1aac1fc93
committer: Oleksandr Byelkin
timestamp: 2016-08-11 17:50:21 +0200
message:

MDEV-10455: libmariadbclient18 + MySQL-python leaks memory on failed connections

Support of CLIENT_REMEMBER_OPTIONS and freeing options added.

Comment by Oleksandr Byelkin [ 2016-08-12 ]

Got OK from Georg.

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