Bug #92963 mysql crash for Dynamic innodb_buffer_pool_size resizing
Submitted: 26 Oct 2018 11:55 Modified: 29 Oct 2018 5:18
Reporter: lalit Choudhary Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.7.24 OS:Any
Assigned to: CPU Architecture:Any
Tags: innodb, MySQL

[26 Oct 2018 11:55] lalit Choudhary
Description:
MySQL crash for Dynamic innodb_buffer_pool_size resizing.

The crash is random when resizing innodb_buffer_pool_size online, this can happen when increasing or decreasing innodb_buffer_pool_size online.

Following are few test cases which result in a crash.

Test1:
mysql> select @@innodb_buffer_pool_size;
+---------------------------+
| @@innodb_buffer_pool_size |
+---------------------------+
|                 134217728 |
+---------------------------+
1 row in set (0.00 sec)

mysql> set global innodb_buffer_pool_size=25769803776;
Query OK, 0 rows affected (0.02 sec)

mysql> use test;
Database changed
mysql> create table t1(c1 int);
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 

-------------
Test2:

mysql> select @@innodb_buffer_pool_size;
+---------------------------+
| @@innodb_buffer_pool_size |
+---------------------------+
|                 134217728 |
+---------------------------+
1 row in set (0.00 sec)

mysql> set global innodb_buffer_pool_size=25769803776;
Query OK, 0 rows affected (0.02 sec)

mysql> use test;
Database changed
mysql> show tables;
Empty set (0.17 sec)

mysql> create table t1(c int);
Query OK, 0 rows affected (0.50 sec)

mysql> show tables;
+----------------+
| Tables_in_test |
+----------------+
| t1             |
+----------------+
1 row in set (0.44 sec)

mysql> select @@innodb_buffer_pool_size;
+---------------------------+
| @@innodb_buffer_pool_size |
+---------------------------+
|               25769803776 |
+---------------------------+
1 row in set (0.05 sec)

mysql> set global innodb_buffer_pool_size=134217728;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    2
Current database: test

Query OK, 0 rows affected (0.03 sec)

mysql>

----------------
test3:

mysql> select @@innodb_buffer_pool_size;
+---------------------------+
| @@innodb_buffer_pool_size |
+---------------------------+
|                 134217728 |
+---------------------------+
1 row in set (0.00 sec)

mysql> set global innodb_buffer_pool_size=25769803776;
Query OK, 0 rows affected (0.02 sec)

mysql> use test;
Database changed
mysql>  create table t1(c int);
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    2
Current database: test

Query OK, 0 rows affected (0.08 sec)

mysql> 

mysql error log:

2018-10-26T11:36:56.242254Z 0 [ERROR] InnoDB: Cannot allocate 63750176 bytes of memory after 60 retries over 60 seconds. OS error: Cannot allocate memory (12). Check if you should increase the swap file or ulimits of your operating system. Note that on most 32-bit computers the process memory space is limited to 2 GB or 4 GB.
2018-10-26 07:36:56 0x7f52183f4700  InnoDB: Assertion failure in thread 139990570845952 in file ut0ut.cc line 957
InnoDB: Failing assertion: !m_fatal
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
11:36:56 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

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

Thread pointer: 0x0
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 = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xf0702b]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x7b93a1]
/lib64/libpthread.so.0(+0xf6d0)[0x7f523cebf6d0]
/lib64/libc.so.6(gsignal+0x37)[0x7f523b8a9277]
/lib64/libc.so.6(abort+0x148)[0x7f523b8aa968]
/usr/sbin/mysqld[0x789704]
/usr/sbin/mysqld(_ZN2ib14fatal_or_errorD2Ev+0x2f8)[0x10ddfe8]
/usr/sbin/mysqld(_ZN12ut_allocatorIhE8allocateEmPKhPKcbb+0x1f2)[0xf535a2]
/usr/sbin/mysqld(_Z12hash0_createm+0x81)[0x11c9851]
/usr/sbin/mysqld(_Z15lock_sys_resizem+0x134)[0xf8f844]
/usr/sbin/mysqld(_Z15buf_pool_resizev+0xcf2)[0x11247b2]
/usr/sbin/mysqld(buf_resize_thread+0x197)[0x11260b7]
/lib64/libpthread.so.0(+0x7e25)[0x7f523ceb7e25]
/lib64/libc.so.6(clone+0x6d)[0x7f523b971bad]
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.
2018-10-26T11:36:57.020333Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2018-10-26T11:36:57.021666Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.24) starting as process 7343 ...
	

How to repeat:
1.start mysql with default settings.

Following are few test cases which result in a crash.

Test1:
mysql> select @@innodb_buffer_pool_size;
+---------------------------+
| @@innodb_buffer_pool_size |
+---------------------------+
|                 134217728 |
+---------------------------+
1 row in set (0.00 sec)

mysql> set global innodb_buffer_pool_size=25769803776;
Query OK, 0 rows affected (0.02 sec)

mysql> use test;
Database changed
mysql> create table t1(c1 int);
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 

-------------
Test2:

mysql> select @@innodb_buffer_pool_size;
+---------------------------+
| @@innodb_buffer_pool_size |
+---------------------------+
|                 134217728 |
+---------------------------+
1 row in set (0.00 sec)

mysql> set global innodb_buffer_pool_size=25769803776;
Query OK, 0 rows affected (0.02 sec)

mysql> use test;
Database changed
mysql> show tables;
Empty set (0.17 sec)

mysql> create table t1(c int);
Query OK, 0 rows affected (0.50 sec)

mysql> show tables;
+----------------+
| Tables_in_test |
+----------------+
| t1             |
+----------------+
1 row in set (0.44 sec)

mysql> select @@innodb_buffer_pool_size;
+---------------------------+
| @@innodb_buffer_pool_size |
+---------------------------+
|               25769803776 |
+---------------------------+
1 row in set (0.05 sec)

mysql> set global innodb_buffer_pool_size=134217728;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    2
Current database: test

Query OK, 0 rows affected (0.03 sec)

mysql>

----------------
test3:

mysql> select @@innodb_buffer_pool_size;
+---------------------------+
| @@innodb_buffer_pool_size |
+---------------------------+
|                 134217728 |
+---------------------------+
1 row in set (0.00 sec)

mysql> set global innodb_buffer_pool_size=25769803776;
Query OK, 0 rows affected (0.02 sec)

mysql> use test;
Database changed
mysql>  create table t1(c int);
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    2
Current database: test

Query OK, 0 rows affected (0.08 sec)

mysql> 

mysql error log:

2018-10-26T11:36:56.242254Z 0 [ERROR] InnoDB: Cannot allocate 63750176 bytes of memory after 60 retries over 60 seconds. OS error: Cannot allocate memory (12). Check if you should increase the swap file or ulimits of your operating system. Note that on most 32-bit computers the process memory space is limited to 2 GB or 4 GB.
2018-10-26 07:36:56 0x7f52183f4700  InnoDB: Assertion failure in thread 139990570845952 in file ut0ut.cc line 957
InnoDB: Failing assertion: !m_fatal
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
11:36:56 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

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

Thread pointer: 0x0
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 = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xf0702b]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x7b93a1]
/lib64/libpthread.so.0(+0xf6d0)[0x7f523cebf6d0]
/lib64/libc.so.6(gsignal+0x37)[0x7f523b8a9277]
/lib64/libc.so.6(abort+0x148)[0x7f523b8aa968]
/usr/sbin/mysqld[0x789704]
/usr/sbin/mysqld(_ZN2ib14fatal_or_errorD2Ev+0x2f8)[0x10ddfe8]
/usr/sbin/mysqld(_ZN12ut_allocatorIhE8allocateEmPKhPKcbb+0x1f2)[0xf535a2]
/usr/sbin/mysqld(_Z12hash0_createm+0x81)[0x11c9851]
/usr/sbin/mysqld(_Z15lock_sys_resizem+0x134)[0xf8f844]
/usr/sbin/mysqld(_Z15buf_pool_resizev+0xcf2)[0x11247b2]
/usr/sbin/mysqld(buf_resize_thread+0x197)[0x11260b7]
/lib64/libpthread.so.0(+0x7e25)[0x7f523ceb7e25]
/lib64/libc.so.6(clone+0x6d)[0x7f523b971bad]
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.
2018-10-26T11:36:57.020333Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2018-10-26T11:36:57.021666Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.24) starting as process 7343 ...
	

Suggested fix:
The expectation here is, it should not crash and show some valid message.
[26 Oct 2018 11:57] lalit Choudhary
Test machine info:

OS has a total memory of 1GB. 

[root@localhost mysql]# cat /etc/redhat-release 
CentOS Linux release 7.5.1804 (Core) 
[root@localhost mysql]# uname -a
Linux localhost.localdomain 3.10.0-862.14.4.el7.x86_64 #1 SMP Wed Sep 26 15:12:11 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
[26 Oct 2018 13:05] Shane Bester
also: https://bugs.mysql.com/bug.php?id=82301
[29 Oct 2018 5:18] Umesh Shastry
Hello Lalit,

Thank you for the report.
This is duplicate of Bug #81654, please see Bug #81654.
Also, Related FR is Bug #82301, which is for user friendly CLI message instead of asserting during online buffer pool resize.

regards,
Umesh