Percona Server moved to https://jira.percona.com/projects/PS

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

  1. Series 5.7
  2. Bug #1693511
Bug #1693511 reported by Kenn Takara
24
This bug affects 4 people
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.7
Triaged
High
Unassigned

Bug Description

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

See original description
Revision history for this message
Kenn Takara (kenn-takara) wrote :
Kenn Takara (kenn-takara)
description: updated
Przemek (pmalkowski)
tags: added: i187595
Revision history for this message
Przemek (pmalkowski) wrote :
Download full text (3.8 KiB)

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

Read more...

Revision history for this message
dikang123 (dikang123) wrote :

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

Laurynas Biveinis (laurynas-biveinis)
tags: added: threadpool
Revision history for this message
Alberto Pastore (bpress) wrote :

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.

Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

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

Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

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

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Bug attachments

Remote bug watches

Bug watches keep track of this bug in other bug trackers.