Memory leak @ read_view_open_now (read0read.c:152/166) in Percona Server 5.5.30-30.2 GA

Do you use jemalloc or any other non-default memory allocation library preloaded?

These settings are too high I'd say:

tmp_table_size = 512M
max_heap_table_size = 512M

Please, upload the output of:

show global status;

to this report.

We use standart memory allocation library.

Based on these:

Connections 92344
Created_tmp_disk_tables 147778
Created_tmp_tables 464737
Uptime_since_flush_status 16608

6 connections per second is made to your system, in average:

mysql> select 92334/16608;
+-------------+
| 92334/16608 |
+-------------+
| 5.5596 |
+-------------+
1 row in set (0.67 sec)

up to 200+ of them runs concurrently:

Max_used_connections 203

and they use temporary tables a lot, 28 per second:

mysql> select 464737/16608;
+--------------+
| 464737/16608 |
+--------------+
| 27.9827 |
+--------------+
1 row in set (0.00 sec)

and even while you let them to be up to 500M in memory, some seems too big and are created on disk:

mysql> select 147778/16608;
+--------------+
| 147778/16608 |
+--------------+
| 8.8980 |
+--------------+
1 row in set (0.00 sec)

9 per second, in average.

So, I'd say up to 8G of memory could easily be used by implicit temporary tables only. Is this enough to explain OOM in your case?

Please, send the output of:

free
ps aux | grep mysqld

also.

I still think there is bug in 5.5.30-30.2, because with previous version server was running fine.

2013-04-18 in the morning I added 4Gb ram to the server. Still after 24h server started to swap:

total used free shared buffers cached
Mem: 17298188 17083796 214392 0 116888 752440
-/+ buffers/cache: 16214468 1083720
Swap: 4095992 2982920 1113072

root 960 0.0 0.0 108296 276 ? S Apr18 0:00 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql --pid-file=/var/lib/mysql/15min-newdb1.pid
mysql 1483 102 89.4 22635872 15478480 ? Sl Apr18 1519:51 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysqld.log --pid-file=/var/lib/mysql/15min-newdb1.pid
root 14441 0.0 0.0 103236 864 pts/0 S+ 07:25 0:00 grep --colour=auto mysqld

Also I have attached Temporary Object graph for one month. There is no significant increase in created tmp tables, so I think that this increased memory usage is because of mysql version.

I'm having the same issue. I have a 60GB memory, 2GB swap machine. Before the upgrade to 5.5.30-2, the swap usage was stable for weeks. After the upgrade, the swap usage is as in the attached image. The load of the machine did not change, neither did anything else. Like in the report of this bug, the kernel kills the mysqld process (currently every 1-2 days).

Similar situation. No issue on 5.5.30-30.1. 48GB of RAM in system. MySQL only configured to use 80%, but is now using 92.4% of system memory on Ubuntu 12.04 64 bit.

I'm monitoring the swap usage closely and have not yet had OOM killer situation, but I will have to restart the process every few days. Attachments show config and status.

InnoDB Status

Global Status

Free output

ps aux | grep mysqld

Performance improvements in 5.5.30-30.2 is the main suspect. We've been trying to reproduce the memory leak on internal tests, but have not succeeded so far. So I have a request to everyone affected by this issue: if you can test a custom-built binary with additional diagnostics, please help us track down this problem.

The additional diagnostics is only available in a source branch currently, but we are going to provide a tarball shortly.

Instructions to build:

bzr branch lp:~percona-core/percona-server/5.5.30-30.2-memory-diagnostics
cd 5.5.30-30.2-memory-diagnostics/Percona-Server
cmake . -DBUILD_CONFIG=mysql_release -DFEATURE_SET=community -DWITH_EMBEDDED_SERVER=OFF -DEXTRA_VERSION="-30.2-memory-diagnostic"

make -j6

You can temporarily replace the installed mysqld binary with the newly built one located in sql/ (don't forget to backup the original binary). Additional diagnostics should not have any measurable overhead. It adds 2 status variables: innodb_read_views_memory and innodb_descriptors_memory.

So when the excessive memory usage can be observed after a few hours, please get the output of

SHOW GLOBAL STATUS LIKE 'innodb%memory';

Thank you.

341,336 (310,992 direct, 30,344 indirect) bytes in 3,534 blocks are definitely lost in loss record 7 of 7
   at 0x4C278FE: malloc (vg_replace_malloc.c:270)
   by 0x859D82: ut_malloc_low (ut0mem.c:102)
   by 0x8073FE: read_view_open_now (read0read.c:152)
   by 0x81DB98: row_search_check_if_query_cache_permitted (row0sel.c:4901)
   by 0x7F7B5B: innobase_query_caching_of_table_permitted(THD*, char*, unsigned int, unsigned long long*) (ha_innodb.cc:2156)
   by 0x55B7D2: Query_cache::ask_handler_allowance(THD*, TABLE_LIST*) (sql_cache.cc:4014)
   by 0x55EB7B: Query_cache::store_query(THD*, TABLE_LIST*) (sql_cache.cc:1468)
   by 0x588A71: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:4796)
   by 0x58D402: mysql_execute_command(THD*) (sql_parse.cc:2300)
   by 0x590C0A: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:5867)
   by 0x59227C: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1062)
   by 0x62FC1E: do_handle_one_connection(THD*) (sql_connect.cc:1487)
   by 0x62FD00: handle_one_connection (sql_connect.cc:1402)
   by 0x4E36850: start_thread (in /lib64/libpthread-2.12.so)
   by 0x5F0211C: clone (in /lib64/libc-2.12.so)

Also,
at 0x4C278FE: malloc (vg_replace_malloc.c:270)
by 0x4C27A72: realloc (vg_replace_malloc.c:662)
by 0x8074A7: read_view_open_now (read0read.c:166)
otherwise same stack.

Version used; lp:~percona-core/percona-server/5.5.30-30.2-memory-diagnostics

One more;

23,056 (18,128 direct, 4,928 indirect) bytes in 206 blocks are definitely lost in loss record 16 of 18
   at 0x4C278FE: malloc (vg_replace_malloc.c:270)
   by 0x859D82: ut_malloc_low (ut0mem.c:102)
   by 0x8073FE: read_view_open_now (read0read.c:152)
   by 0x81DB98: row_search_check_if_query_cache_permitted (row0sel.c:4901)
   by 0x7F7B5B: innobase_query_caching_of_table_permitted(THD*, char*, unsigned int, unsigned long long*) (ha_innodb.cc:2156)
   by 0x55B7D2: Query_cache::ask_handler_allowance(THD*, TABLE_LIST*) (sql_cache.cc:4014)
   by 0x55EB7B: Query_cache::store_query(THD*, TABLE_LIST*) (sql_cache.cc:1468)
   by 0x588A71: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:4796)
   by 0x58D402: mysql_execute_command(THD*) (sql_parse.cc:2300)
   by 0x76E61D: sp_instr_stmt::exec_core(THD*, unsigned int*) (sp_head.cc:3211)
   by 0x76E7A6: sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) (sp_head.cc:2988)
   by 0x77384B: sp_instr_stmt::execute(THD*, unsigned int*) (sp_head.cc:3138)
   by 0x77138E: sp_head::execute(THD*, bool) (sp_head.cc:1433)
   by 0x772716: sp_head::execute_procedure(THD*, List<Item>*) (sp_head.cc:2189)
   by 0x58E9C5: mysql_execute_command(THD*) (sql_parse.cc:4251)
   by 0x590C0A: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:5867)

Extra compile option used; -DWITH_VALGRIND=ON

And another;

44,928 (33,968 direct, 10,960 indirect) bytes in 386 blocks are definitely lost in loss record 19 of 24
   at 0x4C278FE: malloc (vg_replace_malloc.c:270)
   by 0x859D82: ut_malloc_low (ut0mem.c:102)
   by 0x8073FE: read_view_open_now (read0read.c:152)
   by 0x81DB98: row_search_check_if_query_cache_permitted (row0sel.c:4901)
   by 0x7F7B5B: innobase_query_caching_of_table_permitted(THD*, char*, unsigned int, unsigned long long*) (ha_innodb.cc:2156)
   by 0x55B7D2: Query_cache::ask_handler_allowance(THD*, TABLE_LIST*) (sql_cache.cc:4014)
   by 0x55EB7B: Query_cache::store_query(THD*, TABLE_LIST*) (sql_cache.cc:1468)
   by 0x588A71: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:4796)
   by 0x58D402: mysql_execute_command(THD*) (sql_parse.cc:2300)
   by 0x59E3B8: Prepared_statement::execute(String*, bool) (sql_prepare.cc:4110)
   by 0x5A1DAA: Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*) (sql_prepare.cc:3769)
   by 0x5A207A: mysql_sql_stmt_execute(THD*) (sql_prepare.cc:2791)
   by 0x58E7EB: mysql_execute_command(THD*) (sql_parse.cc:2310)
   by 0x590C0A: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:5867)
   by 0x59227C: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1062)
   by 0x62FC1E: do_handle_one_connection(THD*) (sql_connect.cc:1487)

Confirmed as a regression introduced by the fix for bug #1131187. The workaround is to disable the query cache.

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-2940