Bug #96286 mysql server crash when doning buf flushing
Submitted: 23 Jul 2019 9:39 Modified: 14 Apr 3:44
Reporter: Dick Lin Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:5.7.19 OS:Any
Assigned to: MySQL Verification Team CPU Architecture:Any

[23 Jul 2019 9:39] Dick Lin
Description:
When executing sql script like :
ALTER TABLE T00001 ADD COLUMN COLUMN1 VARCHAR(10) COMMENT 'XXXXXXXX', ALGORITHM=INPLACE, LOCK=NONE;
ALTER TABLE T00002 ADD COLUMN COLUMN1 VARCHAR(10) COMMENT 'XXXXXXXX', ALGORITHM=INPLACE, LOCK=NONE;
...
ALTER TABLE T30000 ADD COLUMN COLUMN1 VARCHAR(10) COMMENT 'XXXXXXXX', ALGORITHM=INPLACE, LOCK=NONE;

mysql server crashes with logs below:
key_buffer_size=8388608
read_buffer_size=1048576
max_used_connections=791
max_threads=100001
thread_count=571
connection_count=553
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1740864518 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 0x80000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x2c)[0xed36bc]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x461)[0x7a26e1]
/lib64/libpthread.so.0[0x369ea0f7e0]
/usr/local/mysql/bin/mysqld(_ZN13FlushObserver12notify_flushEP10buf_pool_tP10buf_page_t+0x18)[0x1146648]
/usr/local/mysql/bin/mysqld(_Z14buf_flush_pageP10buf_pool_tP10buf_page_t11buf_flush_tb+0x2e7)[0x1146bb7]
/usr/local/mysql/bin/mysqld[0x11479d3]
/usr/local/mysql/bin/mysqld(_Z18buf_flush_do_batchP10buf_pool_t11buf_flush_tmmPm+0x57f)[0x1148fcf]
/usr/local/mysql/bin/mysqld(buf_flush_page_cleaner_coordinator+0x160c)[0x114d67c]
/lib64/libpthread.so.0[0x369ea07aa1]
/lib64/libc.so.6(clone+0x6d)[0x369e2e893d]

And then mysql server cannot start up with logs below:
key_buffer_size=8388608
read_buffer_size=1048576
max_used_connections=115
max_threads=100001
thread_count=115
connection_count=115
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1740864518 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fbd9a1b8000
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 = 7fc22a0fcbe8 thread_stack 0x80000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x2c)[0xed36bc]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x461)[0x7a26e1]
/lib64/libpthread.so.0[0x369ea0f7e0]
/usr/local/mysql/bin/mysqld(_Z32page_cur_search_with_match_bytesPK11buf_block_tPK12dict_index_tPK8dtuple_t15page_cur_mode_tPmS9_S9_S9_P10page_cur_t+0x16d)[0xfde7dd]
/usr/local/mysql/bin/mysqld(_Z27btr_cur_search_to_nth_levelP12dict_index_tmPK8dtuple_t15page_cur_mode_tmP9btr_cur_tmPKcmP5mtr_t+0xa0d)[0x110bd8d]
/usr/local/mysql/bin/mysqld[0x11125f0]
/usr/local/mysql/bin/mysqld(_ZN11ha_innobase16records_in_rangeEjP12st_key_rangeS1_+0x4e5)[0xf4a465]
/usr/local/mysql/bin/mysqld(_ZN7handler27multi_range_read_info_constEjP15st_range_seq_ifPvjPjS3_P13Cost_estimate+0xc6)[0x7fee56]
/usr/local/mysql/bin/mysqld(_ZN10DsMrr_impl16dsmrr_info_constEjP15st_range_seq_ifPvjPjS3_P13Cost_estimate+0x48)[0x809c38]
/usr/local/mysql/bin/mysqld[0xddfabb]
/usr/local/mysql/bin/mysqld(_Z17test_quick_selectP3THD6BitmapILj64EEyybN8st_order10enum_orderEPK16QEP_shared_ownerP4ItemPS2_PP14QUICK_SELECT_I+0xead)[0xdf14fd]
/usr/local/mysql/bin/mysqld(_ZN4JOIN17estimate_rowcountEv+0x335)[0xc9e115]
/usr/local/mysql/bin/mysqld(_ZN4JOIN14make_join_planEv+0x3ef)[0xca439f]
/usr/local/mysql/bin/mysqld(_ZN4JOIN8optimizeEv+0x57c)[0xca5cbc]
/usr/local/mysql/bin/mysqld(_ZN13st_select_lex8optimizeEP3THD+0x685)[0xcec655]
/usr/local/mysql/bin/mysqld(_Z12handle_queryP3THDP3LEXP12Query_resultyy+0x155)[0xcec835]
/usr/local/mysql/bin/mysqld[0x760ce7]
/usr/local/mysql/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x4816)[0xcb0156]
/usr/local/mysql/bin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x5d5)[0xcb3385]
/usr/local/mysql/bin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xb9b)[0xcb3fab]
/usr/local/mysql/bin/mysqld(_Z10do_commandP3THD+0x1b7)[0xcb5917]
/usr/local/mysql/bin/mysqld(_Z26threadpool_process_requestP3THD+0xc7)[0xd5a267]
/usr/local/mysql/bin/mysqld[0xd6979e]
/usr/local/mysql/bin/mysqld(pfs_spawn_thread+0x1b4)[0x123cf24]
/lib64/libpthread.so.0[0x369ea07aa1]
/lib64/libc.so.6(clone+0x6d)[0x369e2e893d]

How to repeat:
By executing sql script in Description, 4 stand-alone mysql servers crashes.
[23 Jul 2019 12:17] MySQL Verification Team
Hi,
Not reproducing this. Can you share your config file?

thanks
[26 Jul 2019 2:51] Dick Lin
config file

Attachment: my.cnf (application/octet-stream, text), 6.78 KiB.

[30 Jul 2019 23:25] MySQL Verification Team
Hi,

I cannot reproduce this with 5.7.26 neither on linux (centos, rhel, ol and fedora) nor on macos (10.14.5). I created 30000 tables no problem, then I altered them, again no problem.

With this many tables you want to increase table cache and max open files both on os and on mysql itself also not that file per table is default on
[14 Apr 3:44] Dick Lin
updated MySQL server to 5.7.26, and crashed again, with almost same error log:

key_buffer_size=8388608
read_buffer_size=1048576
max_used_connections=6
max_threads=100001
thread_count=19
connection_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1740864893 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 0x80000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x2c)[0xee0ecc]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x461)[0xd21621]
/lib64/libpthread.so.0[0x369ea0f7e0]
/usr/local/mysql/bin/mysqld(_ZN13FlushObserver12notify_flushEP10buf_pool_tP10buf_page_t+0x18)[0x118dc68]
/usr/local/mysql/bin/mysqld(_Z14buf_flush_pageP10buf_pool_tP10buf_page_t11buf_flush_tb+0x317)[0x118e207]
/usr/local/mysql/bin/mysqld[0x118f103]
/usr/local/mysql/bin/mysqld(_Z18buf_flush_do_batchP10buf_pool_t11buf_flush_tmmPm+0x57f)[0x119070f]
/usr/local/mysql/bin/mysqld[0x1192f61]
/usr/local/mysql/bin/mysqld(buf_flush_page_cleaner_worker+0x185)[0x1193255]
/lib64/libpthread.so.0[0x369ea07aa1]
/lib64/libc.so.6(clone+0x6d)[0x369e2e893d]
[14 Apr 12:06] MySQL Verification Team
Hi,
Still can't reproduce this. Without a way to reproduce this there's little we can do. Maybe if you run a debug version of mysql server on your stage and can reproduce there we could gather some useful data.

Thanks
Bogdan