Percona Server 5.7 memory usage keeps growing with perf schema + thread pooling

[Kenn Takara]

Ran across this issue when running PMM with PXC 5.7 (reproed this with Percona Server 5.7.17 on Centos7 with THP disabled and with/without jemalloc)

The server has no activity except for PMM. The memory usage of the process grows until killed.

Repro case (does not require PMM):
(1) Start the server
(2) Run the following test script

        #!/bin/bash

        while true
        do
            mysql -Spath/to/socket.sock -uroot -e "SELECT EVENT_NAME FROM performance_schema.file_summary_by_event_name;" > /dev/null
        done

What happens:
the memory usage keeps growing until the process or the script is killed

Expect:
The memory usage to stabilize at some point

=======================

This appears to be a combination of the performance schema and thread pooling. Here's the output from running top.

Output after starting the test script
  performance_schema=ON
  thread-handling=pool-of-threads

      PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2017-05-25-05:43:05 20260 kennt 20 0 4545832 393380 20408 S 0.0 10.2 0:02.07 mysqld
2017-05-25-05:43:08 20260 kennt 20 0 4545832 393380 20408 S 0.7 10.2 0:02.09 mysqld
>> started the test script
2017-05-25-05:43:11 20260 kennt 20 0 4562732 393908 20436 S 9.3 10.2 0:02.37 mysqld
2017-05-25-05:43:14 20260 kennt 20 0 4564292 434824 20436 S 43.3 11.2 0:03.67 mysqld
2017-05-25-05:43:17 20260 kennt 20 0 4564292 516656 20436 S 43.2 13.4 0:04.97 mysqld
2017-05-25-05:43:20 20260 kennt 20 0 4564292 557572 20436 S 42.7 14.4 0:06.25 mysqld
2017-05-25-05:43:23 20260 kennt 20 0 4564292 598488 20436 S 42.9 15.5 0:07.54 mysqld
2017-05-25-05:43:26 20260 kennt 20 0 4564292 639404 20436 S 42.9 16.5 0:08.83 mysqld
2017-05-25-05:43:29 20260 kennt 20 0 4564292 680320 20436 S 42.3 17.6 0:10.10 mysqld
(this will keep growing)
2017-05-25-05:44:05 20260 kennt 20 0 5023044 988.9m 20548 S 0.3 26.2 0:20.43 mysqld
2017-05-25-05:44:08 20260 kennt 20 0 5023044 991.2m 20728 S 0.3 26.3 0:20.44 mysqld

Output after starting the script with performance_schema=OFF
  performance_schema=OFF
  thread-handling=pool-of-threads

      PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2017-05-25-05:46:14 24348 kennt 20 0 4394072 260772 20308 S 0.3 6.7 0:01.87 mysqld
2017-05-25-05:46:20 24348 kennt 20 0 4394072 260772 20308 S 0.0 6.7 0:01.87 mysqld
>> started the test script
2017-05-25-05:46:20 24348 kennt 20 0 4412532 261300 20340 S 9.6 6.8 0:02.16 mysqld
2017-05-25-05:46:23 24348 kennt 20 0 4412532 261300 20340 S 11.0 6.8 0:02.49 mysqld
2017-05-25-05:46:26 24348 kennt 20 0 4412532 261300 20340 S 11.3 6.8 0:02.83 mysqld
2017-05-25-05:46:29 24348 kennt 20 0 4412532 261300 20340 S 11.3 6.8 0:03.17 mysqld
2017-05-25-05:46:32 24348 kennt 20 0 4412532 261300 20340 S 10.6 6.8 0:03.49 mysqld

Output after starting the script with thread-handling commented out
  performance_schema=ON
  #thread-handling=pool-of-threads

      PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2017-05-25-05:48:12 27277 kennt 20 0 4537668 393232 20424 S 0.3 10.2 0:02.00 mysqld
2017-05-25-05:48:15 27277 kennt 20 0 4537668 393232 20424 S 0.0 10.2 0:02.00 mysqld
>> started the test script
2017-05-25-05:48:18 27277 kennt 20 0 4537668 393480 20572 S 4.7 10.2 0:02.14 mysqld
2017-05-25-05:48:21 27277 kennt 20 0 4537668 393480 20572 S 43.0 10.2 0:03.43 mysqld
2017-05-25-05:48:24 27277 kennt 20 0 4537668 393480 20572 S 42.5 10.2 0:04.71 mysqld
2017-05-25-05:48:27 27277 kennt 20 0 4537668 393480 20572 S 42.5 10.2 0:05.99 mysqld
2017-05-25-05:48:30 27277 kennt 20 0 4537668 393480 20572 S 43.0 10.2 0:07.28 mysqld

[Przemek (pmalkowski)]

I can confirm that on PS 5.7.18

Without Thread Pool enabled, memory usage is stable after thousands of iterations on reading P_S tables, and mem usage with default settings of sandbox ends up like this:

USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
przemyslaw.malkowski@bm-support01:~/sandboxes$ ps aux|grep 'port=25718'|grep -v grep
10095 25636 4.0 0.0 724624 184244 pts/136 Sl 05:15 0:10 /home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.18/bin/mysqld --defaults-file=/home/przemyslaw.malkowski/sandboxes/ps5.7.18/my.sandbox.cnf --basedir=/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.18 --datadir=/home/przemyslaw.malkowski/sandboxes/ps5.7.18/data --plugin-dir=/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.18/lib/mysql/plugin --log-error=/home/przemyslaw.malkowski/sandboxes/ps5.7.18/data/msandbox.err --pid-file=/home/przemyslaw.malkowski/sandboxes/ps5.7.18/data/mysql_sandbox25718.pid --socket=/tmp/mysql_sandbox25718.sock --port=25718

while with setting added:
thread-handling=pool-of-threads

przemyslaw.malkowski@bm-support01:~/sandboxes$ for i in {1..3000};do ps5.7.18/use -e "select * from sys.memory_global_total" > /dev/null; done

USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
10095 18537 50.3 0.3 1535568 717076 pts/136 Sl 05:37 2:51 /home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.18/bin/mysqld --defaults-file=/home/przemyslaw.malkowski/sandboxes/ps5.7.18/my.sandbox.cnf --basedir=/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.18 --datadir=/home/przemyslaw.malkowski/sandboxes/ps5.7.18/data --plugin-dir=/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.18/lib/mysql/plugin --log-error=/home/przemyslaw.malkowski/sandboxes/ps5.7.18/data/msandbox.err --pid-file=/home/przemyslaw.malkowski/sandboxes/ps5.7.18/data/mysql_sandbox25718.pid --socket=/tmp/mysql_sandbox25718.sock --port=25718

and the more iterations, the higher the mem goes, so looks like a clear memory leak.

Some mem stats after 3k iterations:
mysql [localhost] {msandbox} ((none)) > select event_name, high_number_of_bytes_used/1024/1024 high_number_of_bytes_used_MB from performance_schema.memory_summary_global_by_event_name order by high_number_of_bytes_used desc limit 10;
+-----------------------------------------------------------------------------+------------------------------+
| event_name | high_number_of_bytes_used_MB |
+-----------------------------------------------------------------------------+------------------------------+
| memory/sql/sp_head::main_mem_root | 350.41809082 |
| memory/innodb/buf_buf_pool | 133.25000000 |
| memory/performance_schema/events_statements_summary_by_thread_by_event_name | 118.54882813 |
| memory/sql/String::value | 93.85099030 |
| memory/sql/thd::main_mem_root | 93.54455566 |
| memory/performance_s...

[dikang123 (dikang123)]

Anyone can tell me could this bug be fixed in percona server 5.7.19?

[Alberto Pastore (bpress)]

I've just set up a fresh installation on a test machine of version 5.7.19 (small VM with 6GB RAM)
The server is totally idle (no connections, no queries running), but after 1 hour both ram & swap are full and an oom is triggered.

So the problem is still present in the most recent available version.

As soon as I disable either performance_schema or thread pooling, the problem does not occur.

[Shahriyar Rzayev (rzayev-sehriyar)]

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

[Shahriyar Rzayev (rzayev-sehriyar)]

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