MySQL Bugs: #71759: memory leak with string thread variable that set memalloc flag

Bug #71759	memory leak with string thread variable that set memalloc flag
Submitted:	18 Feb 2014 13:50	Modified:	23 Jul 2015 1:32
Reporter:	richard prohaska	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Storage Engine API	Severity:	S3 (Non-critical)
Version:	5.6.21	OS:	Linux
Assigned to:		CPU Architecture:	Any
Tags:	memory leak, MYSQL_THDVAR_STR, PLUGIN_VAR_MEMALLOC, thdvar

Description:
e have a thread variable of type MYSQL_THDVAR_STR and with the
PLUGIN_VAR_MEMALLOC flag set.  this variable gets set by the tokudb
storage  engine with malloc'ed memory.  we expect that the memory will
be freed when the thread context (THD) gets destroyed.  this works
corrected on MariaDB 5.5.35.  unfortunately, the memory for this
variable gets leaked on MySQL 5.5.36 and MySQL 5.6.16 (and probably
other versions).

the key difference between MySQL and MariaDB WRT this leak is in the
cleanup_variables function.  MariaDB has code that free's the memory
for these variables while MySQL does not.

How to repeat:
Need to add a thread variable to the example storage engine and run some mtr valgrind tests with it.

Thank you for the report.

I see that all thread variables get cleaned up in plugin_thdvar_cleanup by calling cleanup_variables(thd, &thd->variables) and cleanup_variables, in its turn, frees everything:

static void cleanup_variables(THD *thd, struct system_variables *vars)
{
  if (thd)
    plugin_var_memalloc_free(&thd->variables);

  DBUG_ASSERT(vars->table_plugin == NULL);
  DBUG_ASSERT(vars->temp_table_plugin == NULL);

  my_free(vars->dynamic_variables_ptr);
  vars->dynamic_variables_ptr= NULL;
  vars->dynamic_variables_size= 0;
  vars->dynamic_variables_version= 0;
}

If it does not do so in your case please send us example of code, demonstrating the issue. Ideally would be if you could modify a built-in storage engine or provide example for the example storage engine.

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".

Sveta - no other way to verify this bug?

Here is a reproducer:  https://github.com/Tokutek/tokudb-engine/wiki/MySQL-leaks-memory-for-str-type-thread-varia...

MySQL leaks the memory for str type thread variables.
Step 1. Add a str type thread variable to the example storage engine.  Use it in the ha_example::create method to capture the name of the last created table.  Here we allocate 100MB of memory so that the leak can easily be seen with valgrind.

$ diff ha_example.cc ~/Downloads/mysql-5.6.21/storage/example
881d880
< static MYSQL_THDVAR_STR(last_create, PLUGIN_VAR_MEMALLOC, "last_create", NULL /*check*/, NULL /*update*/, NULL /*default*/);
910,914d908
<   THD *thd = ha_thd();
<   my_free(THDVAR(thd, last_create));
<   char *sp = (char *) my_malloc(100000000, MYF(MY_FAE)); // allocate 100MB so that it is easily seen with valgrind
<   sprintf(sp, "%s:%u %s", __FILE__, __LINE__, name);
<   THDVAR(thd, last_create) = sp;
987d980
<   MYSQL_SYSVAR(last_create),

Step 2. Run mysqld with valgrind.

Step 3. Install the example storage engine.

Step 4. Create a couple of tables using the example storage engine.  This should call the ha_example::create method a couple of times.

Step 5. Shutdown mysql and check the valgrind report for leaks.  We found it when using MySQL 5.6.21.

==11276== 100,000,000 bytes in 1 blocks are definitely lost in loss record 256 of 257
==11276==    at 0x4C2AB80: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==11276==    by 0xA7FC0D: my_malloc (my_malloc.c:38)
==11276==    by 0x37C44D20: ???
==11276==    by 0x6354CB: handler::ha_create(char const*, TABLE*, st_ha_create_information*) (handler.cc:4524)
==11276==    by 0x635D53: ha_create_table(THD*, char const*, char const*, char const*, st_ha_create_information*, bool, bool) (handler.cc:4762)
==11276==    by 0x8955D1: rea_create_table(THD*, char const*, char const*, char const*, st_ha_create_information*, List<Create_field>&, unsigned int, st_key*, handler*, bool) (unireg.cc:527)
==11276==    by 0x82DB6D: create_table_impl(THD*, char const*, char const*, char const*, st_ha_create_information*, Alter_info*, bool, unsigned int, bool, bool*, st_key**, unsigned int*) (sql_table.cc:4919)
==11276==    by 0x82E08B: mysql_create_table_no_lock(THD*, char const*, char const*, st_ha_create_information*, Alter_info*, unsigned int, bool*) (sql_table.cc:5029)
==11276==    by 0x82E19B: mysql_create_table(THD*, TABLE_LIST*, st_ha_create_information*, Alter_info*) (sql_table.cc:5078)
==11276==    by 0x7C2D29: mysql_execute_command(THD*) (sql_parse.cc:3061)
==11276==    by 0x7CB586: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:6245)
==11276==    by 0x7BEEEE: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1332)
==11276== 
==11276== 277,600,000 bytes in 1 blocks are still reachable in loss record 257 of 257
==11276==    at 0x4C2D110: memalign (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==11276==    by 0x4C2D227: posix_memalign (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==11276==    by 0xDA3F1D: pfs_malloc(unsigned long, int) (pfs_global.cc:57)
==11276==    by 0xDAA4E2: init_table_share(unsigned int) (pfs_instr_class.cc:344)
==11276==    by 0xDACE26: initialize_performance_schema(PFS_global_param*) (pfs_server.cc:88)
==11276==    by 0x619D1E: mysqld_main(int, char**) (mysqld.cc:5250)
==11276==    by 0x6107DC: main (main.cc:25)
==11276== 
==11276== LEAK SUMMARY:
==11276==    definitely lost: 100,000,000 bytes in 1 blocks
==11276==    indirectly lost: 0 bytes in 0 blocks
==11276==      possibly lost: 352,120 bytes in 1,149 blocks
==11276==    still reachable: 557,343,016 bytes in 49 blocks
==11276==         suppressed: 0 bytes in 0 blocks

on mariadb, the memory is freed in cleanup_variables.

#0  my_free (ptr=0x7ffd9e400070) at /home/rfp/mariadb-10.0.14/mysys/my_malloc.c:208
#1  0x0000000000661d0e in cleanup_variables (thd=0x7ffd9b614070, vars=0x7ffd9b614730) at /home/rfp/mariadb-10.0.14/sql/sql_plugin.cc:3138
#2  0x0000000000661e1c in plugin_thdvar_cleanup (thd=0x7ffd9b614070) at /home/rfp/mariadb-10.0.14/sql/sql_plugin.cc:3162
#3  0x000000000076c50f in end_connection (thd=0x7ffd9b614070) at /home/rfp/mariadb-10.0.14/sql/sql_connect.cc:1175
#4  0x000000000076cc3a in do_handle_one_connection (thd_arg=0x7ffd9b614070) at /home/rfp/mariadb-10.0.14/sql/sql_connect.cc:1382
#5  0x000000000076c97e in handle_one_connection (arg=0x7ffd9b614070) at /home/rfp/mariadb-10.0.14/sql/sql_connect.cc:1293
#6  0x00007ffff733c182 in start_thread (arg=0x7ffff7f6c700) at pthread_create.c:312
#7  0x00007ffff6222fbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thank you for the report.

I cannot repeat described behavior with 50 tables. How many tables do you create? Where did you download MySQL sources? Did you modify them? How do you compile them?

I added a string type thread variable to the example storage engine and used valgrind to identify a memory leak WRT that thread varable.  I also added more information to this wiki https://github.com/Tokutek/tokudb-engine/wiki/MySQL-leaks-memory-for-str-type-thread-varia... about how to reproduce the problem.

Thank you for the feedback.
Followed the steps and observed a similar mem leak issue on Debian GNU/Linux 7 (wheezy)/Valgrind 3.10

==20897== 3,800,000,000 bytes in 38 blocks are possibly lost in loss record 245 of 245
==20897==    at 0x4C29554: malloc (vg_replace_malloc.c:296)
==20897==    by 0xA9B951: my_malloc (my_malloc.c:38)
==20897==    by 0xB81056E: ???
==20897==    by 0x66525D: handler::ha_create(char const*, TABLE*, st_ha_create_information*) (handler.cc:4524)
==20897==    by 0x665AEF: ha_create_table(THD*, char const*, char const*, char const*, st_ha_create_information*, bool, bool) (handler.cc:4762)
==20897==    by 0x8BBB21: rea_create_table(THD*, char const*, char const*, char const*, st_ha_create_information*, List<Create_field>&, unsigned int, st_key*, handler*, bool) (unireg.cc:527)
==20897==    by 0x855E0C: create_table_impl(THD*, char const*, char const*, char const*, st_ha_create_information*, Alter_info*, bool, unsigned int, bool, bool*, st_key**, unsigned int*) (sql_table.cc:4919)
==20897==    by 0x8562C8: mysql_create_table_no_lock(THD*, char const*, char const*, st_ha_create_information*, Alter_info*, unsigned int, bool*) (sql_table.cc:5029)
==20897==    by 0x8563C8: mysql_create_table(THD*, TABLE_LIST*, st_ha_create_information*, Alter_info*) (sql_table.cc:5078)
==20897==    by 0x7EE099: mysql_execute_command(THD*) (sql_parse.cc:3061)
==20897==    by 0x7F68DB: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:6245)
==20897==    by 0x7EA35D: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1332)
==20897== 
==20897== LEAK SUMMARY:
==20897==    definitely lost: 1,200,000,000 bytes in 12 blocks
==20897==    indirectly lost: 0 bytes in 0 blocks
==20897==      possibly lost: 3,800,248,024 bytes in 1,211 blocks
==20897==    still reachable: 75,089,328 bytes in 54 blocks
==20897==         suppressed: 0 bytes in 0 blocks
==20897== 
==20897== For counts of detected and suppressed errors, rerun with: -v
==20897== ERROR SUMMARY: 191 errors from 191 contexts (suppressed: 6 from 6)

test results

Attachment: 71759.txt (text/plain), 38.77 KiB.

Some analysis: 

For values set by the server it handles allocations and deallocations properly, including cleanup_variables() etc. It does this by calling plugin_var_memalloc_free() from cleanup_variables()

But for that to work one needs to properly update the string session variable by calling plugin_var_memalloc_session_update() instead of THDVAR(name)= new_value.

However this is a static function not exported to plugin code so this makes it hard for plugins to properly update such variable.

Noted in 5.8.0 changelog.

Assignment by a plugin to its thread variables of string type could
leak memory.