long startup time with many tables, performance_schema=On and open_files_limit > 65534

[Ian Bissett]

We have a Percona Cluster 5.6.16 server with approximately 10,000 databases and a total of approximately 1.5 million tables (~150 tables per Database) as part of our multi-tenant database infrastructure (one database per customer).

When we have performance_schema=On and open_files_limit set to more than 65534 the startup time of the MySQL Daemon takes a extremely long time.

General startup time with our dataset is approximately 2-5 Minutes as all of the tables are read (in a single threaded process).

Crash recovery takes on average approximately 20-30 Minutes on our hardware (again, this is a single-threaded process to load all the tables).

When performance_schema=On and open_files_limit >= 65534 startup time is in excess of 90 minutes (in fact it took so long to start that we never waited for it to complete).

All of our databases are named with sequential numbers and using lsof we could see which tables were being opened. The process appeared to be getting much slower as it progressed through the tables on disk.

With performance_schema=Off and open_files_limit >= 65534 startup time returns to normal.

Please let me know what information you would like me to provide.

[Valerii Kravchuk (valerii-kravchuk)]

Thank you for the problem report. I suspect this is a problem inherited from upstream MySQL 5.6.x.

Please, send your my.cnf file content and the output of:

show engine performance_schema status;

when performance_schema is ON. How many tables do you have on this instance, in all databases in total?

[Ian Bissett (bisscuitt-e)]

my.cnf

[Ian Bissett (bisscuitt-e)]

mysql> SELECT COUNT(*) FROM information_schema.tables;
+----------+
| COUNT(*) |
+----------+
| 1484698 |
+----------+
1 row in set (1 min 52.81 sec)

[Nilnandan Joshi (nilnandan-joshi)]

I was able to reproduce the same with 79000 tables on PS 5.6.20

mysql> SELECT COUNT(*) FROM information_schema.tables where table_schema = 'bugtest';
+----------+
| COUNT(*) |
+----------+
| 79723 |
+----------+
1 row in set (0.25 sec)

If performance_schema=off and open_files_limit = 66000, then server will be started within 2 seconds.

root@Dell-XPS:/var/lib/mysql# date && /etc/init.d/mysql start && date
Thu Sep 18 15:09:37 IST 2014
 * Starting MySQL (Percona Server) database server mysqld [ OK ]
 * Checking for corrupt, not cleanly closed and upgrade needing tables.
Thu Sep 18 15:09:39 IST 2014
root@Dell-XPS:/var/lib/mysql#

But If performance_schema=on and open_files_limit = 66000, then server will take 16-20 seconds. (tried 2-3 times)
root@Dell-XPS:/var/lib/mysql# vim /etc/mysql/my.cnf
root@Dell-XPS:/var/lib/mysql#
root@Dell-XPS:/var/lib/mysql# date && /etc/init.d/mysql start && date
Thu Sep 18 15:10:01 IST 2014
 * Starting MySQL (Percona Server) database server mysqld [ OK ]
Thu Sep 18 15:10:19 IST 2014
root@Dell-XPS:/var/lib/mysql#

[Jai Gupta (jai-g)]

Is http://dba.stackexchange.com/questions/60165/what-variables-to-look-to-maintain-mysql-speed-of-scanning-through-all-databas/60544#60544 related?

[Laurynas Biveinis (laurynas-biveinis)]

Nil, have you checked upstream?

[Nilnandan Joshi (nilnandan-joshi)]

Hi Laurynas,

I have tried to check the same scenario with MySQL 5.6.20 community server but unable to reproduce it.

with, performance_schema=on and open_files_limit = 67000,

root@Dell-XPS:~# date && /etc/init.d/mysql start && date
Mon Sep 22 16:01:37 IST 2014
No directory, logging in with HOME=/
......
 * MySQL Community Server 5.6.20 is started
Mon Sep 22 16:01:44 IST 2014
root@Dell-XPS:~#

With performance_schema=off and open_files_limit = 67000

root@Dell-XPS:~# vim /etc/mysql/my.cnf
root@Dell-XPS:~#
root@Dell-XPS:~# date && /etc/init.d/mysql start && date
Mon Sep 22 16:02:07 IST 2014
No directory, logging in with HOME=/
......
 * MySQL Community Server 5.6.20 is started
Mon Sep 22 16:02:13 IST 2014
root@Dell-XPS:~#

[Nilnandan Joshi (nilnandan-joshi)]

It seems, this is resolved in latest version. Server version: 5.6.25-73.1-log Percona Server.

root@desktop:~# head -33 /etc/mysql/my.cnf | tail -3
[mysqld]
performance_schema=off
open_files_limit = 66000
root@desktop:~#
root@desktop:~# date && /etc/init.d/mysql start && date
Wed Jul 22 11:53:29 IST 2015
 * Starting MySQL (Percona Server) database server mysqld [ OK ]
Wed Jul 22 11:53:30 IST 2015
root@desktop:~#
root@desktop:~# vim /etc/mysql/my.cnf
root@desktop:~#
root@desktop:~# head -33 /etc/mysql/my.cnf | tail -3
[mysqld]
performance_schema=on
open_files_limit = 66000
root@desktop:~#
root@desktop:~# date && /etc/init.d/mysql start && date
Wed Jul 22 11:53:49 IST 2015
 * Starting MySQL (Percona Server) database server mysqld [ OK ]
Wed Jul 22 11:53:49 IST 2015
root@desktop:~#

[Ian Bissett (bisscuitt)]

I've just tested this on our staging platform with 219794 tables
Server version: 5.6.25-73.1-log Percona Server (GPL), Release 73.1, Revision 07b797f

# grep -iE '(performance_schema|open_files_limit)' /etc/mysql/my.cnf; date; /etc/init.d/mysql start; date
open_files_limit=4000000
performance_schema=OFF

Tue Aug 4 00:26:39 CDT 2015
Starting MySQL (Percona Server) database server: mysqld . . . . . . . . . . ..
Checking for corrupt, not cleanly closed and upgrade needing tables..
Tue Aug 4 00:26:52 CDT 2015

# grep -iE '(performance_schema|open_files_limit)' /etc/mysql/my.cnf; date; /etc/init.d/mysql start; date
open_files_limit=4000000
performance_schema=ON
Tue Aug 4 00:29:27 CDT 2015
Starting MySQL (Percona Server) database server: mysqld . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . failed!
Tue Aug 4 00:44:53 CDT 2015

It eventually started after about 20 minutes (/var/log/mysql/mysql.log):
...
2015-08-04 00:29:46 23639 [Note] InnoDB: Completed initialization of buffer pool
2015-08-04 00:29:47 23639 [Note] InnoDB: Highest supported file format is Barracuda.
2015-08-04 00:49:36 23639 [Note] InnoDB: 128 rollback segment(s) are active.
...
2015-08-04 00:49:38 23639 [Note] /usr/sbin/mysqld: ready for connections.

It looks like this is related to open_files_limit in conjunction with the number of databases when performance_schema is enabled.

[Shahriyar Rzayev (rzayev-sehriyar)]

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