| Bug #72719 | Performance Schema behavior on hosts with low RAM | ||
|---|---|---|---|
| Submitted: | 22 May 2014 6:58 | Modified: | 18 Jul 2014 12:25 |
| Reporter: | Will Fong | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Performance Schema | Severity: | S3 (Non-critical) |
| Version: | 5.6.17 | OS: | Linux (CentOS 6) |
| Assigned to: | CPU Architecture: | Any | |
[16 Jul 2014 13:04]
MySQL Verification Team
Thank you for the report. Verified as described. Thanks, Umesh
[16 Jul 2014 13:05]
MySQL Verification Team
*** On a newly setup VMBox with 1G memory
With swap enabled - max connections upto 5000 works without any issues, >5000, it fails with "InnoDB: mmap(137363456 bytes) failed; errno 12"
Without swap - >=2500
2014-07-16 18:20:46 4229 [Note] InnoDB: Initializing buffer pool, size = 128.0M
InnoDB: mmap(137363456 bytes) failed; errno 12
2014-07-16 18:20:46 4229 [ERROR] InnoDB: Cannot allocate memory for the buffer pool
2014-07-16 18:20:46 4229 [ERROR] Plugin 'InnoDB' init function returned error.
2014-07-16 18:20:46 4229 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2014-07-16 18:20:46 4229 [ERROR] Unknown/unsupported storage engine: InnoDB
2014-07-16 18:20:46 4229 [ERROR] Aborting
mysql invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0, oom_score_adj=0
mysql cpuset=/ mems_allowed=0
Pid: 4904, comm: mysql Not tainted 2.6.32-431.el6.x86_64 #1
[ 4904] 0 4904 26525 89 0 0 0 mysql
[ 4910] 0 4910 26558 73 0 0 0 mysqld_safe
[ 5026] 0 5026 180856 152472 0 0 0 mysqld
Out of memory: Kill process 5026 (mysqld) score 599 or sacrifice child
Killed process 5026, UID 0, (mysqld) total-vm:723424kB, anon-rss:609756kB, file-rss:132kB
[root@ushastry Desktop]# cat /var/log/messages|grep -i mysql
Jul 16 18:27:08 ushastry kernel: mysql invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0, oom_score_adj=0
Jul 16 18:27:08 ushastry kernel: mysql cpuset=/ mems_allowed=0
Jul 16 18:27:08 ushastry kernel: Pid: 4904, comm: mysql Not tainted 2.6.32-431.el6.x86_64 #1
Jul 16 18:27:08 ushastry kernel: [ 4904] 0 4904 26525 89 0 0 0 mysql
Jul 16 18:27:08 ushastry kernel: [ 4910] 0 4910 26558 73 0 0 0 mysqld_safe
Jul 16 18:27:08 ushastry kernel: [ 5026] 0 5026 180856 152472 0 0 0 mysqld
Jul 16 18:27:08 ushastry kernel: Out of memory: Kill process 5026 (mysqld) score 599 or sacrifice child
Jul 16 18:27:08 ushastry kernel: Killed process 5026, UID 0, (mysqld) total-vm:723424kB, anon-rss:609756kB, file-rss:132kB
///
[root@ushastry Downloads]# rpm -qa|grep -i mysql
MySQL-embedded-5.6.17-1.el6.x86_64
MySQL-server-5.6.17-1.el6.x86_64
MySQL-shared-5.6.17-1.el6.x86_64
MySQL-devel-5.6.17-1.el6.x86_64
MySQL-test-5.6.17-1.el6.x86_64
MySQL-client-5.6.17-1.el6.x86_64
MySQL-shared-compat-5.6.17-1.el6.x86_64
[root@ushastry Downloads]# free -m -t
total used free shared buffers cached
Mem: 996 486 509 0 7 132
-/+ buffers/cache: 346 649
Swap: 0 0 0
Total: 996 486 509
// OS
[root@ushastry Downloads]# cat /etc/*release
CentOS release 6.5 (Final)
LSB_VERSION=base-4.0-amd64:base-4.0-noarch:core-4.0-amd64:core-4.0-noarch:graphics-4.0-amd64:graphics-4.0-noarch:printing-4.0-amd64:printing-4.0-noarch
CentOS release 6.5 (Final)
CentOS release 6.5 (Final)
[18 Jul 2014 12:24]
Marc ALFF
Thanks for your interest in the performance_schema. Quoting the bug description: " At 2000 max_connections, MySQL does not start anymore because there is not enough RAM for the buffer pool. Expected, PS got the RAM first. " This is the expected result then. " At 3000 max_connections, MySQL starts, but PS cannot allocate enough RAM, so it gets disabled. Expected. Up to this point, things make sense. " This is the expected result then. " At 3500 max_connections, MySQL does not start, not able to allocate the buffer pool. But the error log says PS was disabled " Quoting results seen: " 3500 - Cannot allocate buffer pool. Buffered warning: Performance schema disabled (reason: init failed). " The server indicates that: - the innodb buffer pool was not allocated. - the performance_schema itself was disabled. Two failures occurred (the first is fatal, the second is not), and both failures are visible in the server log. This is the expected result. " At 4750 max_connections, it can start. " Whether the server can actually start with max_connection=N is irrelevant. What matters is if the server can actually function under the expected load, when the number of concurrent connections actually reaches N. Each connection (without using a thread pool) needs 1 thread. Each thread needs by default 256 Kb of memory, for the thread stack alone. With 4750 connections, the memory used for thread stacks is: 256 Kb * 4750 = 1216000 Kb = 1.16 Gb A server with 1 Gb of RAM will never service a peak load of 4750 connections, and keep in mind that this consumption of 1.16 Gb is for stack memory alone, even before a single byte of heap memory is allocated. Any attempt to operate a server with 1 Gb of memory and a greater value for max_connection (up to 15 thousands in the bug report, really ?) is bound to fail, regardless of whether the performance_schema is used or not. When allocating memory fails: - by a "soft" error, as in malloc() returns NULL, a message is printed in the mysql server log - by a "hard" error, as in killed by the OOM killer in linux, a message is printed in the host log. Failures are logged in all cases. Closing as not a bug.
Description: I'm seeing some interesting behavior with Performance Schema on systems with low RAM. For example, I'm running a VM with 1GB of RAM (VMware Fusion) without any swap. I got the PS memory usage from SHOW ENGINE PERFORMANCE_SCHEMA STATUS. At 2000 max_connections, MySQL does not start anymore because there is not enough RAM for the buffer pool. Expected, PS got the RAM first. At 3000 max_connections, MySQL starts, but PS cannot allocate enough RAM, so it gets disabled. Expected. Up to this point, things make sense. At 3500 max_connections, MySQL does not start, not able to allocate the buffer pool. But the error log says PS was disabled At 4750 max_connections, it can start. Connections - Results: 1500 - Starts. PS Used: 663528448 1750 - Starts. PS Used: 709098240 2000 - Does not start. Error: Cannot allocate buffer pool 2014-05-22 21:50:20 4758 [Note] InnoDB: Initializing buffer pool, size = 128.0M InnoDB: mmap(137363456 bytes) failed; errno 12 2014-05-22 21:50:20 4758 [ERROR] InnoDB: Cannot allocate memory for the buffer pool 2250 - Does not start. Cannot allocate buffer pool 2500 - Does not start. Cannot allocate buffer pool 2750 - Does not start. Only Starting/ended log lines in error log 140522 22:04:25 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql 140522 22:04:26 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended Checking in /var/log/messages, we see an OOM May 22 22:04:26 mysqldev kernel: Out of memory: Kill process 6064 (mysqld) score 852 or sacrifice child May 22 22:04:26 mysqldev kernel: Killed process 6064, UID 0, (mysqld) total-vm:971604kB, anon-rss:861248kB, file-rss:8kB 3000 - Started. PS Used: 874755200 Buffered warning: Performance schema disabled (reason: init failed). 3000 - PS off. Started. PS Used: 0 3250 - Started. PS Used: 920324992 3500 - Cannot allocate buffer pool. Buffered warning: Performance schema disabled (reason: init failed). 3750 - Cannot allocate buffer pool. Buffered warning: Performance schema disabled (reason: init failed). 4000 - Cannot allocate buffer pool. Buffered warning: Performance schema disabled (reason: init failed). 4750 - Started. PS Used: 1193744448. Buffered warning: Performance schema disabled (reason: init failed). 5000 - Started. PS Used: 1239314240. Buffered warning: Performance schema disabled (reason: init failed). 5250 - Started. PS Used: 1284884032. Buffered warning: Performance schema disabled (reason: init failed). 5500 - Started. PS Used: 1330453824. Buffered warning: Performance schema disabled (reason: init failed). 7000 - Started. PS Used: 1603873280. Buffered warning: Performance schema disabled (reason: init failed). 7250 - Started. PS Used: 1649443072. Buffered warning: Performance schema disabled (reason: init failed). 7500 - Cannot allocate buffer pool. Buffered warning: Performance schema disabled (reason: init failed). 8000 - Cannot allocate buffer pool. Buffered warning: Performance schema disabled (reason: init failed). 9000 - Cannot allocate buffer pool. Buffered warning: Performance schema disabled (reason: init failed). 10000 - Cannot allocate buffer pool. Buffered warning: Performance schema disabled (reason: init failed). 15000 - Started. PS Used: 3062108032. Buffered warning: Performance schema disabled (reason: init failed). More interesting is the RAM usage when MySQL says Performance Schema is off: Max connections at 3000, MySQL started and error logged this: Buffered warning: Performance schema disabled (reason: init failed). total used free shared buffers cached Mem: 1012348 849192 163156 0 4660 38060 -/+ buffers/cache: 806472 205876 Swap: 0 0 0 Max connections at 3000 and performance_schema=off: total used free shared buffers cached Mem: 1012348 182100 830248 0 4764 38068 -/+ buffers/cache: 139268 873080 Swap: 0 0 0 So even if MySQL says performance schema is off, it doesn't seem to really be. Very concerning (and not sure if I should file another bug report) but at max_connections 2750, no error log messages were printed, and the kernel OOM killed MySQL. It would be much nicer if it was logged like InnoDB. Testing on a different VM environment (e.g., Digital Ocean 1GB droplet), I saw the same behavior but at different max_connection values. I guess it is specifically how much RAM the host has. Printing the allocated memory for PS would be great, as suggested in #69665 How to repeat: Installed 5.6.17 via Oracle RPM repo. Using stock/default configuration. I only added max_connections under [mysqld]. Start/stop with "service mysqld start|stop"