Bug #33807 mysql_real_query memory leak
Submitted: 10 Jan 2008 20:41 Modified: 4 Jan 2009 4:46
Reporter: Peter Beniaris Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: C API (client library) Severity:S1 (Critical)
Version:5.0.51 OS:Linux (Slackware 12.0)
Assigned to: CPU Architecture:Any
Tags: memory leak

[10 Jan 2008 20:41] Peter Beniaris
Description:
I am using mysql_real_query() for SELECT and INSERT statements.  For SELECT statements, I am able to store and free the results, and memory is freed as expected.  For INSERT statements, I have no result to store, and simply call mysql_real_query.  Each INSERT results is a very small loss of memory, but if I create a large enough loop of INSERTs, I can watch memory leak using the top command.  I performed 1,000,000 inserts on a two column table with a VARCHAR(5), and a DATE, and the resulting loss of memory was approximately 12MB each time I ran the loop.  I searched the bug reports and found a similar bug (#29676), but it only addresses memory leaks for queries that do not return results for the embedded server.  I was using 5.0.37, and after reading the fix for 29676 was pushed to 5.0.48, I upgraded to see if that would help, but it did not.

How to repeat:
- Create a table of any format
- Prepare an INSERT statement
- use mysql_real_query to insert
- Iterate the statement several times (I used 1, 10, 1000, etc.)
- Watch the memory drain using top or free
[11 Jan 2008 4:29] Valeriy Kravchuk
Thank you for a problem report. Please, send a complete C code for a test case.
[11 Jan 2008 15:06] Peter Beniaris
#include <iostream>
#include <fstream>
#include <cstdlib>
#include <ctime>
#include <my_global.h>
#include <mysql.h>

using namespace std;

int main(int argc, char* argv[]) {
	// initalize a MySQL connection handler
	MYSQL* conn;
	conn = mysql_init(NULL);

	// get username and password
	ifstream nkhpass;
	string userid, passwd;
	nkhpass.open("/home/nkhadmin/.nkhpass", ios_base::in);
	nkhpass >> userid >> passwd;
	nkhpass.close();

	// intialize program timer
	time_t rawtime;
	struct tm* timeinfo;
	time(&rawtime);
	timeinfo = localtime(&rawtime);

	// connect to the database
	if (!mysql_real_connect(conn,"localhost",userid.c_str(),passwd.c_str(),"nkh",0,NULL,0)) {
		cerr << "connection failed: " << mysql_errno(conn) << ": " << mysql_error(conn) << endl;
		exit(EXIT_FAILURE);
	}
	else {
		time(&rawtime);
		timeinfo = localtime(&rawtime);
		cout << "successfully connected to database at: " << asctime(timeinfo);
	}

	// initialize string to hold sql statements
	char* sql;

	// drop demo table and ready for reload
	sql = "DROP TABLE IF EXISTS demo";
	if (mysql_real_query(conn, sql, strlen(sql)) !=0)
		cerr << "demo table drop failed: " << mysql_errno(conn) << ": " << mysql_error(conn) << endl;
	else {
		time(&rawtime);
		timeinfo = localtime(&rawtime);
		cout << "successfully dropped demo table at: " << asctime(timeinfo);
	}
	
	// recreate demo table
	sql  = "CREATE TABLE demo ( symbol VARCHAR(5) NOT NULL, \
			trdate DATE NOT NULL)";
	
	if (mysql_real_query(conn, sql, strlen(sql)) !=0)
		cerr << "demo table create failed: " << mysql_errno(conn) << ": " << mysql_error(conn) << endl;
	else {
		time(&rawtime);
		timeinfo = localtime(&rawtime);
		cout << "successfully created demo table at: " << asctime(timeinfo);
	}

	// create insert statement
	sql = "INSERT INTO demo VALUES ('12345', '2008-01-11')";
	
	// insert a million records into demo table
	for (int i = 0; i < 1000000; i++) {
		mysql_real_query(conn, sql, strlen(sql));
	}

	time(&rawtime);
	timeinfo = localtime(&rawtime);
	cout << "completed data load into demo at: " << asctime(timeinfo);
	
	// disconnect from the database and exit the program
	mysql_close(conn);
	time(&rawtime);
	timeinfo = localtime(&rawtime);
	cout << "successfully completed demo load at: " << asctime(timeinfo);
	exit(EXIT_SUCCESS);
}
[3 Dec 2008 15:40] Brett Schoppert
I appear to be having the exact same problem, has any progress been made on this bug report ?
[4 Dec 2008 0:03] MySQL Verification Team
I couldn't repeat this issue with latest source server under Valgrind running on laptop ACER ASPIRE 5920 2GB RAM 64-bit and Ubuntu 8.10. Top just showed high CPU usage but not high memory usage. I compiled a C application similar to the test case provided:

miguel@hegel:~/dbs/5.0$ sh -c "gcc -o bug33807 `$CFG --cflags` ./bug33807.c `$CFG --libs`"
miguel@hegel:~/dbs/5.0$ ./bug33807
Test begin: 2008-12-03 21:16:51
Client version: 5.0.76
Connected to the server: 5.0.76-valgrind-max-debug
Table demo dropped
Table demo created
Begin to insert 1000000 records: 2008-12-03 21:16:51
Test end: 2008-12-03 21:51:32
miguel@hegel:~/dbs/5.0$ 

--8091-- REDIR: 0x5dc0990 (realloc) redirected to 0x4c26600 (realloc)
081203 20:22:57 [Note] /home/miguel/dbs/5.0/libexec/mysqld: ready for connections.
Version: '5.0.76-valgrind-max-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
==8091== 
==8091== Thread 10:
==8091== Conditional jump or move depends on uninitialised value(s)
==8091==    at 0x8ADA97: strmake (strmake.c:44)
==8091==    by 0x89005A: fn_format (mf_format.c:92)
==8091==    by 0x637C57: create_tmp_table(THD*, TMP_TABLE_PARAM*, List<Item>&, st_order*, bool, bool, unsigned long long, unsigned long long, char*) (sql_select.cc:9311)
==8091==    by 0x6F7F04: create_schema_table(THD*, TABLE_LIST*) (sql_show.cc:3708)
==8091==    by 0x6F0872: mysql_schema_table(THD*, st_lex*, TABLE_LIST*) (sql_show.cc:3920)
==8091==    by 0x621B16: open_tables(THD*, TABLE_LIST**, unsigned*, unsigned) (sql_base.cc:2734)
==8091==    by 0x621FED: open_and_lock_tables(THD*, TABLE_LIST*) (sql_base.cc:3060)
==8091==    by 0x5F3823: mysql_execute_command(THD*) (sql_parse.cc:2756)
==8091==    by 0x5F9410: mysql_parse(THD*, char const*, unsigned, char const**) (sql_parse.cc:6266)
==8091==    by 0x5FBBC7: dispatch_command(enum_server_command, THD*, char*, unsigned) (sql_parse.cc:1938)
==8091==    by 0x5FD845: handle_one_connection (sql_parse.cc:1628)
==8091==    by 0x54573E9: start_thread (in /lib/libpthread-2.8.90.so)
--8091-- REDIR: 0x5dc6fc0 (__memcpy_chk) redirected to 0x4c281d0 (__memcpy_chk)
081203 21:52:53 [Note] Got signal 15 to shutdown mysqld
081203 21:52:53 [Note] /home/miguel/dbs/5.0/libexec/mysqld: Normal shutdown

081203 21:52:53  InnoDB: Starting shutdown...
081203 21:52:55  InnoDB: Shutdown completed; log sequence number 0 43655
081203 21:52:55 [Note] /home/miguel/dbs/5.0/libexec/mysqld: Shutdown complete

--8091-- Discarding syms at 0xD1DA000-0xD3E6000 in /lib/libnss_files-2.8.90.so due to munmap()
==8091== 
==8091== ERROR SUMMARY: 12 errors from 2 contexts (suppressed: 28 from 3)

<cut>

==8091== LEAK SUMMARY:
==8091==    definitely lost: 0 bytes in 0 blocks.
==8091==      possibly lost: 2,176 bytes in 8 blocks.
==8091==    still reachable: 1,540 bytes in 5 blocks.
==8091==         suppressed: 0 bytes in 0 blocks.
--8091--  memcheck: sanity checks: 157688 cheap, 540 expensive
--8091--  memcheck: auxmaps: 0 auxmap entries (0k, 0M) in use
--8091--  memcheck: auxmaps_L1: 0 searches, 0 cmps, ratio 0:10
--8091--  memcheck: auxmaps_L2: 0 searches, 0 nodes
--8091--  memcheck: SMs: n_issued      = 749 (11984k, 11M)
--8091--  memcheck: SMs: n_deissued    = 301 (4816k, 4M)
--8091--  memcheck: SMs: max_noaccess  = 524287 (8388592k, 8191M)
--8091--  memcheck: SMs: max_undefined = 307 (4912k, 4M)
--8091--  memcheck: SMs: max_defined   = 1591 (25456k, 24M)
--8091--  memcheck: SMs: max_non_DSM   = 664 (10624k, 10M)
--8091--  memcheck: max sec V bit nodes:    585 (50k, 0M)
--8091--  memcheck: set_sec_vbits8 calls: 585 (new: 585, updates: 0)
--8091--  memcheck: max shadow mem size:   14818k, 14M
--8091-- translate:            fast SP updates identified: 24,687 ( 85.5%)
--8091-- translate:   generic_known SP updates identified: 3,997 ( 13.8%)
--8091-- translate: generic_unknown SP updates identified: 162 (  0.5%)
--8091--     tt/tc: 64,087,440 tt lookups requiring 88,122,251 probes
--8091--     tt/tc: 64,087,440 fast-cache updates, 3 flushes
--8091--  transtab: new        20,461 (686,231 -> 9,156,463; ratio 133:10) [0 scs]
--8091--  transtab: dumped     0 (0 -> ??)
--8091--  transtab: discarded  112 (1,986 -> ??)
--8091-- scheduler: 15,758,978,668 jumps (bb entries).
--8091-- scheduler: 157,688/112,320,959 major/minor sched events.
--8091--    sanity: 157689 cheap, 540 expensive checks.
--8091--    exectx: 1,543 lists, 1,104 contexts (avg 0 per list)
--8091--    exectx: 38,068,939 searches, 38,156,141 full compares (1,002 per 1000)
--8091--    exectx: 17 cmp2, 358 cmp4, 0 cmpAll
--8091--  errormgr: 34 supplist searches, 965 comparisons during search
--8091--  errormgr: 40 errlist searches, 430 comparisons during search
miguel@hegel:~/dbs$
[4 Dec 2008 0:52] MySQL Verification Team
Valgrind report for client application:

--18702-- REDIR: 0x5b96f40 (index) redirected to 0x4c26a20 (index)
Client version: 5.0.76
Connected to the server: 5.0.76-valgrind-max-debug
Table demo dropped
Table demo created
Begin to insert 1000000 records: 2008-12-03 22:08:58
Test end: 2008-12-03 22:49:03
--18702-- Discarding syms at 0x64A3000-0x66AF000 in /lib/libnss_files-2.8.90.so due to munmap()
==18702== 
==18702== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 27 from 3)
--18702-- 
--18702-- supp:      1 dl-hack4-64bit-addr-1
--18702-- supp:     25 dl-hack3-cond-1
--18702-- supp:      1 dl-hack4-64bit-addr-2
==18702== malloc/free: in use at exit: 44,992 bytes in 12 blocks.
==18702== malloc/free: 78 allocs, 66 frees, 95,260 bytes allocated.
==18702== 
==18702== searching for pointers to 12 not-freed blocks.
==18702== checked 572,408 bytes.
==18702== 
==18702== 24 bytes in 1 blocks are still reachable in loss record 1 of 2
==18702==    at 0x4C265AE: malloc (vg_replace_malloc.c:207)
==18702==    by 0x4E86D92: my_malloc (my_malloc.c:34)
==18702==    by 0x4E88137: my_error_register (my_error.c:173)
==18702==    by 0x4E867C5: init_client_errs (errmsg.c:229)
==18702==    by 0x4E84FE3: mysql_server_init (libmysql.c:128)
==18702==    by 0x4EAFC45: mysql_init (client.c:1488)
==18702==    by 0x400C70: main (bug33807.c:32)
==18702== 
==18702== 
==18702== 44,968 bytes in 11 blocks are still reachable in loss record 2 of 2
==18702==    at 0x4C265AE: malloc (vg_replace_malloc.c:207)
==18702==    by 0x4E8F937: my_once_alloc (my_once.c:61)
==18702==    by 0x4E9009A: init_state_maps (charset.c:62)
==18702==    by 0x4E90A14: init_available_charsets (charset.c:435)
==18702==    by 0x4E90BE9: get_charset_by_csname (charset.c:577)
==18702==    by 0x4EAFA13: mysql_init_character_set (client.c:1759)
==18702==    by 0x4EB2449: mysql_real_connect (client.c:2161)
==18702==    by 0x400CA8: main (bug33807.c:35)
==18702== 
==18702== LEAK SUMMARY:
==18702==    definitely lost: 0 bytes in 0 blocks.
==18702==      possibly lost: 0 bytes in 0 blocks.
==18702==    still reachable: 44,992 bytes in 12 blocks.
==18702==         suppressed: 0 bytes in 0 blocks.
--18702--  memcheck: sanity checks: 9823 cheap, 120 expensive
--18702--  memcheck: auxmaps: 0 auxmap entries (0k, 0M) in use
--18702--  memcheck: auxmaps_L1: 0 searches, 0 cmps, ratio 0:10
--18702--  memcheck: auxmaps_L2: 0 searches, 0 nodes
--18702--  memcheck: SMs: n_issued      = 29 (464k, 0M)
--18702--  memcheck: SMs: n_deissued    = 0 (0k, 0M)
--18702--  memcheck: SMs: max_noaccess  = 524287 (8388592k, 8191M)
--18702--  memcheck: SMs: max_undefined = 0 (0k, 0M)
--18702--  memcheck: SMs: max_defined   = 379 (6064k, 5M)
--18702--  memcheck: SMs: max_non_DSM   = 29 (464k, 0M)
--18702--  memcheck: max sec V bit nodes:    2 (0k, 0M)
--18702--  memcheck: set_sec_vbits8 calls: 2 (new: 2, updates: 0)
--18702--  memcheck: max shadow mem size:   4608k, 4M
--18702-- translate:            fast SP updates identified: 3,749 ( 87.1%)
--18702-- translate:   generic_known SP updates identified: 423 (  9.8%)
--18702-- translate: generic_unknown SP updates identified: 131 (  3.0%)
--18702--     tt/tc: 9,480 tt lookups requiring 9,875 probes
--18702--     tt/tc: 9,480 fast-cache updates, 3 flushes
--18702--  transtab: new        4,649 (106,337 -> 1,620,777; ratio 152:10) [0 scs]
--18702--  transtab: dumped     0 (0 -> ??)
--18702--  transtab: discarded  112 (1,986 -> ??)
--18702-- scheduler: 982,400,394 jumps (bb entries).
--18702-- scheduler: 9,823/3,014,988 major/minor sched events.
--18702--    sanity: 9824 cheap, 120 expensive checks.
--18702--    exectx: 769 lists, 106 contexts (avg 0 per list)
--18702--    exectx: 171 searches, 73 full compares (426 per 1000)
--18702--    exectx: 11 cmp2, 296 cmp4, 0 cmpAll
--18702--  errormgr: 28 supplist searches, 447 comparisons during search
--18702--  errormgr: 27 errlist searches, 345 comparisons during search
[4 Dec 2008 3:00] Brett Schoppert
So, you tested on 5.0.76 and didn't see a leak.

The latest released version for 5.0 is 5.0.67 ... I'm currently using 5.0.51 and see the leak, if I test on 5.0.67 and still see it, do I need to submit a valgrind report for you to believe it is there ?
[4 Dec 2008 4:46] Valeriy Kravchuk
If 5.0.67 still has this problem, please, send Valgrind report. But note that we do not fix bugs in older version anyway, so if 5.0.76 (current one) does not have it, then we'd assume it was fixed somehow in the process.
[4 Dec 2008 6:41] Brett Schoppert
5.0.76 isn't even on the download site ... the latest I see is 5.0.67 ... how can the latest available version be "older" ?

Anyway, if 5.0.76 fixes the problem, when will it be available on the download site for general production usage ?
[4 Dec 2008 15:24] Valeriy Kravchuk
You can get sources of current 5.0.x from https://code.launchpad.net/~mysql/mysql-server/mysql-5.0.
[5 Jan 2009 0:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".