It's possible to have innodb_open_files>open_files_limit and it can crash Percona Server

Bug #1510564 reported by Kenny Gryp
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
New
Undecided
Unassigned
5.6
Fix Released
High
Unassigned
5.7
Fix Released
High
Unassigned

Bug Description

(As reported in http://bugs.mysql.com/bug.php?id=78981)

Description:
It's possible to have innodb_open_files>open_files_limit::

+-------------------+-------+
| Variable_name | Value |
+-------------------+-------+
| innodb_open_files | 16384 |
| open_files_limit | 8510 |
+-------------------+-------+

Having open_files_limit < innodb_open_files is not normal, it only seems to be possible to configure it like this when innodb_open_files>16384 and open_files_limit is not defined.

With MySQL 5.6.27 (coming from a production environment), you get the following crash::

```
2015-10-27 10:20:33 5535 [ERROR] InnoDB: Trying to do i/o to a tablespace which exists without .ibd data file. i/o type 10, space id 11015335, page no 0, i/o length 16384 bytes
2015-10-27 10:20:33 7fa725a05700 InnoDB: Error: trying to access tablespace 11015335 page no. 0,
InnoDB: but the tablespace does not exist or is just being dropped.
2015-10-27 10:20:33 7fa725a05700 InnoDB: Operating system error number 24 in a file operation.
InnoDB: Error number 24 means 'Too many open files'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2015-10-27 10:20:33 7fa725a057002015-10-27 10:20:33 5535 [Warning] InnoDB: InnoDB: Error: cannot open ./shard07/event_log_1310#P#p20151119.ibd
. InnoDB: Have you deleted .ibd files under a running mysqld server?

...

2015-10-27 10:20:33 5535 [ERROR] InnoDB: Trying to do i/o to a tablespace which exists without .ibd data file. i/o type 10, space id 11015335, page no 0, i/o length 16384 bytes
2015-10-27 10:20:33 7fa725a05700 InnoDB: Error: trying to access tablespace 11015335 page no. 0,
InnoDB: but the tablespace does not exist or is just being dropped.
2015-10-27 10:20:33 7fa725a05700 InnoDB: Operating system error number 24 in a file operation.
InnoDB: Error number 24 means 'Too many open files'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2015-10-27 10:20:33 7fa725a057002015-10-27 10:20:33 5535 [Warning] InnoDB: InnoDB: Error: cannot open ./shard07/event_log_1310#P#p20151119.ibd
. InnoDB: Have you deleted .ibd files under a running mysqld server?

2015-10-27 10:20:33 5535 [ERROR] InnoDB: Trying to do i/o to a tablespace which exists without .ibd data file. i/o type 10, space id 11015335, page no 0, i/o length 16384 bytes
2015-10-27 10:20:33 7fa725a05700 InnoDB: Error: trying to access tablespace 11015335 page no. 0,
InnoDB: but the tablespace does not exist or is just being dropped.
InnoDB: Error: Unable to read tablespace 11015335 page no 0 into the buffer pool after 100 attempts
InnoDB: The most probable cause of this error may be that the table has been corrupted.
InnoDB: You can try to fix this problem by using innodb_force_recovery.
InnoDB: Please see reference manual for more details.
InnoDB: Aborting...
2015-10-27 10:20:33 7fa725a05700 InnoDB: Assertion failure in thread 140355867531008 in file buf0buf.cc line 2740
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
09:20:33 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.

key_buffer_size=16777216
read_buffer_size=131072
max_used_connections=69
max_threads=500
thread_count=41
connection_count=40
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2134782 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fa7193dfc40
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7fa725a04e38 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x9149f5]
/usr/sbin/mysqld(handle_fatal_signal+0x3f1)[0x682fe1]
/lib64/libpthread.so.0(+0xf7c0)[0x7fd8f92487c0]
/lib64/libc.so.6(gsignal+0x35)[0x7fd8f7d0bb55]
/lib64/libc.so.6(abort+0x181)[0x7fd8f7d0d131]
/usr/sbin/mysqld[0xad4012]
/usr/sbin/mysqld[0xb21410]
/usr/sbin/mysqld[0x9cf944]
/usr/sbin/mysqld(_ZN12ha_partition4infoEj+0x32e)[0xb5ca8e]
/usr/sbin/mysqld[0x739ee6]
/usr/sbin/mysqld[0x73e51c]
/usr/sbin/mysqld(_Z14get_all_tablesP3THDP10TABLE_LISTP4Item+0x6da)[0x748fba]
/usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x2e1)[0x735011]
/usr/sbin/mysqld(_ZN4JOIN14prepare_resultEPP4ListI4ItemE+0x9d)[0x728e4d]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x13f)[0x6e3dbf]
/usr/sbin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_P10SQL_I_ListI8st_orderESB_S7_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x198)[0x72f288]
/usr/sbin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x19f)[0x72f48f]
/usr/sbin/mysqld[0x7059fd]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x3595)[0x709db5]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x388)[0x70ba88]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x176f)[0x70da0f]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x11f)[0x6d6b5f]
/usr/sbin/mysqld(handle_one_connection+0x45)[0x6d6c35]
/usr/sbin/mysqld(pfs_spawn_thread+0x126)[0x9adfb6]
/lib64/libpthread.so.0(+0x77b6)[0x7fd8f92407b6]
/lib64/libc.so.6(clone+0x6d)[0x7fd8f7db09cd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (147612830): show table status like 'event\_log\_1310'
Connection ID (thread ID): 104064
Status: NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
```

How to repeat:
Script to Reproduce:

```
#!/bin/bash
# configure mysql with the following settings (doublecheck innodb_open_files<=open_files_limit):
#+----------------------------+----------+
#| Variable_name | Value |
#+----------------------------+----------+
#| innodb_open_files | 16384 |
#| open_files_limit | 16384 |
#+----------------------------+----------+
mysqladmin create test
unionquery="SELECT 1"
# creating many files here (innodb_file_per_table is on be default). We should create more than 5000
for tables in `seq 1 1 10`; do
 mysql -e "create table Stolen$tables (a int) partition by hash(a) partitions 1024;" test
 unionquery="$unionquery UNION select * from Stolen$tables "
done
echo "now remove open_files_limit from the mysql configuration and restart mysql"
echo "you should have innodb_open_files>open_files_limit:"
echo "+----------------------------+----------+"
echo "| Variable_name | Value |"
echo "+----------------------------+----------+"
echo "| innodb_open_files | 16384 |"
echo "| open_files_limit | 5000 |"
echo "+----------------------------+----------+"
echo "then run the following query:"
echo "$unionquery"
```

Having open_files_limit < innodb_open_files is not normal, it only seems to be possible to configure it like this when innodb_open_files>16384.

When you run the query, then in the error log you get the errors and crash of MySQL:

Percona Server 5.6.26 (created with the reproducing script)::
```
2015-10-27 14:16:36 19887 [ERROR] InnoDB: Trying to do i/o to a tablespace which exists without .ibd data file. i/o type 10, space id 63140, page no 3, i/o length 16384 bytes
2015-10-27 14:16:36 7f70c01d3700 InnoDB: Error: trying to access tablespace 63140 page no. 3,
InnoDB: but the tablespace does not exist or is just being dropped.
2015-10-27 14:16:36 7f70c01d3700 InnoDB: Operating system error number 24 in a file operation.
InnoDB: Error number 24 means 'Too many open files'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2015-10-27 14:16:36 7f70c01d37002015-10-27 14:16:36 19887 [Warning] InnoDB: InnoDB: Error: cannot open ./test/Stolen5#P#p871.ibd
. InnoDB: Have you deleted .ibd files under a running mysqld server?

...

...

2015-10-27 14:16:36 19887 [ERROR] InnoDB: Trying to do i/o to a tablespace which exists without .ibd data file. i/o type 10, space id 63140, page no 3, i/o length 16384 bytes
2015-10-27 14:16:36 7f70c01d3700 InnoDB: Error: trying to access tablespace 63140 page no. 3,
InnoDB: but the tablespace does not exist or is just being dropped.
2015-10-27 14:16:36 7f70c01d3700 InnoDB: Operating system error number 24 in a file operation.
InnoDB: Error number 24 means 'Too many open files'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2015-10-27 14:16:36 7f70c01d37002015-10-27 14:16:36 19887 [Warning] InnoDB: InnoDB: Error: cannot open ./test/Stolen5#P#p871.ibd
. InnoDB: Have you deleted .ibd files under a running mysqld server?

2015-10-27 14:16:36 19887 [ERROR] InnoDB: Trying to do i/o to a tablespace which exists without .ibd data file. i/o type 10, space id 63140, page no 3, i/o length 16384 bytes
2015-10-27 14:16:36 7f70c01d3700 InnoDB: Error: trying to access tablespace 63140 page no. 3,
InnoDB: but the tablespace does not exist or is just being dropped.
2015-10-27 14:16:36 7f70c01d3700 InnoDB: Operating system error number 24 in a file operation.
InnoDB: Error number 24 means 'Too many open files'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2015-10-27 14:16:36 7f70c01d37002015-10-27 14:16:36 19887 [Warning] InnoDB: InnoDB: Error: cannot open ./test/Stolen5#P#p871.ibd
. InnoDB: Have you deleted .ibd files under a running mysqld server?

2015-10-27 14:16:36 19887 [ERROR] InnoDB: Trying to do i/o to a tablespace which exists without .ibd data file. i/o type 10, space id 63140, page no 3, i/o length 16384 bytes
2015-10-27 14:16:36 7f70c01d3700 InnoDB: Error: trying to access tablespace 63140 page no. 3,
InnoDB: but the tablespace does not exist or is just being dropped.
InnoDB: Error: Unable to read tablespace 63140 page no 3 into the buffer pool after 100 attempts
InnoDB: The most probable cause of this error may be that the table has been corrupted.
InnoDB: You can try to fix this problem by using innodb_force_recovery.
InnoDB: Please see reference manual for more details.
InnoDB: Aborting...
2015-10-27 14:16:36 7f70c01d3700 InnoDB: Assertion failure in thread 140122236204800 in file buf0buf.cc line 2788
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
14:16:36 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=2
connection_count=2
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 69048 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x3f85dd0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f70c01d2d80 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0x8dd32b]
/usr/sbin/mysqld(handle_fatal_signal+0x471)[0x65a811]
/lib64/libpthread.so.0(+0xf130)[0x7f70dfb58130]
/lib64/libc.so.6(gsignal+0x37)[0x7f70de1055d7]
/lib64/libc.so.6(abort+0x148)[0x7f70de106cc8]
/usr/sbin/mysqld[0xa755a4]
/usr/sbin/mysqld[0xa576d4]
/usr/sbin/mysqld[0x9fbe4b]
/usr/sbin/mysqld[0x947841]
/usr/sbin/mysqld[0x93a9f0]
/usr/sbin/mysqld[0x949bdf]
/usr/sbin/mysqld(_ZN7handler11ha_rnd_nextEPh+0xac)[0x59c85c]
/usr/sbin/mysqld(_ZN12ha_partition8rnd_nextEPh+0x4a)[0xb6320a]
/usr/sbin/mysqld(_ZN7handler11ha_rnd_nextEPh+0x6c)[0x59c81c]
/usr/sbin/mysqld(_Z13rr_sequentialP11READ_RECORD+0x20)[0x80d830]
/usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0xdd)[0x6bc2fd]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x2e8)[0x6bb578]
/usr/sbin/mysqld(_ZN18st_select_lex_unit4execEv+0x313)[0x74a263]
/usr/sbin/mysqld(_Z11mysql_unionP3THDP3LEXP13select_resultP18st_select_lex_unitm+0x92)[0x74b8e2]
/usr/sbin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x85)[0x706c05]
/usr/sbin/mysqld[0x55c836]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x1a9c)[0x6df11c]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x5b8)[0x6e47e8]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x105b)[0x6e5feb]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x172)[0x6b21d2]
/usr/sbin/mysqld(handle_one_connection+0x40)[0x6b22d0]
/usr/sbin/mysqld(pfs_spawn_thread+0x143)[0x9157f3]
/lib64/libpthread.so.0(+0x7df5)[0x7f70dfb50df5]
/lib64/libc.so.6(clone+0x6d)[0x7f70de1c61ad]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f708c004d60): is an invalid pointer
Connection ID (thread ID): 4
Status: NOT_KILLED

You may download the Percona Server operations manual by visiting
http://www.percona.com/software/percona-server/. You may find information
in the manual which will help you identify the cause of the crash.
151027 14:16:36 mysqld_safe Number of processes running now: 0
```

Suggested fix:
Make sure that innodb_open_files cannot be larger open_files_limit.

Tags: upstream
tags: added: upstream
Revision history for this message
Kenny Gryp (gryp) wrote :

This bug is verified in upstream

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

Kenny, please keep us posted on the upstream bug updates as it has become private now

Revision history for this message
Kenny Gryp (gryp) wrote :

Laurynas, according to the upstream bug, this is fixed as of the upcoming 5.6.30, 5.7.12, 5.8.0 release

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

Great, thanks Kenny

Revision history for this message
Yura Sorokin (yura-sorokin) wrote :

The fix is now in 5.6 trunk after upstream 5.6.30 merge.

Revision history for this message
Yura Sorokin (yura-sorokin) wrote :
Revision history for this message
Yura Sorokin (yura-sorokin) wrote :

The fix will be in 5.7 trunk after upstream 5.7.12 merge.
https://github.com/percona/percona-server/pull/542

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

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

Other bug subscribers

Remote bug watches

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