[MDEV-8188] Server hangs on shutdown in logs_empty_and_mark_files_at_shutdown Created: 2015-05-20  Updated: 2018-03-13  Resolved: 2018-03-13

Status: Closed
Project: MariaDB Server
Component/s: Plugins, Storage Engine - InnoDB
Affects Version/s: 10.0, 10.1, 10.2
Fix Version/s: 10.0.35, 10.1.32, 10.2.14, 10.3.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Duplicate Votes: 2
Labels: None

Issue Links:
Relates
relates to MDEV-14648 Restore fix for MySQL BUG#39053 - UNI... Closed
relates to MDEV-15554 InnoDB page_cleaner shutdown sometime... Closed
Sprint: 10.2.14

 Description    

--source include/have_innodb.inc
 
 
 
create table t1 (i int) engine=InnoDB;
 
 
 
uninstall soname 'ha_innodb';
 
 
 
--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
 
--shutdown_server 60
 
--source include/wait_until_disconnected.inc
 
 
 
--cat_file $MYSQLTEST_VARDIR/log/mysqld.1.err
 
 
 
--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
 
--enable_reconnect
 
--source include/wait_until_connected_again.inc
 
 
 
drop table t1;

The test takes 60+ seconds (after which MTR just kills the server); and the log shows that shutdown didn't finish.

Stack trace from the running server, 10.0 commit 0880284bf

 
#1  0x00007f44d6fc85db in os_thread_sleep (tm=100000) at 10.0/storage/innobase/os/os0thread.cc:261
 
#2  0x00007f44d6fad1e5 in logs_empty_and_mark_files_at_shutdown () at 10.0/storage/innobase/log/log0log.cc:3226
 
#3  0x00007f44d7093d4d in innobase_shutdown_for_mysql () at 10.0/storage/innobase/srv/srv0start.cc:2961
 
#4  0x00007f44d6f453c3 in innobase_end (hton=0x7f44d9ff2270, type=HA_PANIC_CLOSE) at 10.0/storage/innobase/handler/ha_innodb.cc:3475
 
#5  0x000000000086de63 in ha_finalize_handlerton (plugin=0x7f44d9feb7b0) at 10.0/sql/handler.cc:440
 
#6  0x0000000000690f54 in plugin_deinitialize (plugin=0x7f44d9feb7b0, ref_check=true) at 10.0/sql/sql_plugin.cc:1175
 
#7  0x000000000069131b in reap_plugins () at 10.0/sql/sql_plugin.cc:1248
 
#8  0x000000000069161d in plugin_unlock (thd=0x0, plugin=0x7f44cb8511f0) at 10.0/sql/sql_plugin.cc:1320
 
#9  0x0000000000752ebd in TABLE_SHARE::destroy (this=0x7f44cb864a88) at 10.0/sql/table.cc:429
 
#10 0x000000000075304e in free_table_share (share=0x7f44cb864a88) at 10.0/sql/table.cc:470
 
#11 0x00000000007fd854 in tdc_delete_share_from_hash (share=0x7f44cb864a88) at 10.0/sql/table_cache.cc:452
 
#12 0x00000000007fdca0 in tdc_purge (all=true) at 10.0/sql/table_cache.cc:586
 
#13 0x00000000006190ce in close_cached_tables (thd=0x0, tables=0x0, wait_for_refresh=false, timeout=31536000) at 10.0/sql/sql_base.cc:451
 
#14 0x00000000007fda55 in tdc_start_shutdown () at 10.0/sql/table_cache.cc:519
 
#15 0x00000000005bed6b in clean_up (print_message=true) at 10.0/sql/mysqld.cc:2028
 
#16 0x00000000005beb20 in unireg_end () at 10.0/sql/mysqld.cc:1936
 
#17 0x00000000005bea42 in kill_server (sig_ptr=0x0) at 10.0/sql/mysqld.cc:1864
 
#18 0x00000000005bea5f in kill_server_thread (arg=0x7f44e0648e28) at 10.0/sql/mysqld.cc:1887
 
#19 0x0000000000cd7363 in pfs_spawn_thread (arg=0x7f44cb42c0f0) at 10.0/storage/perfschema/pfs.cc:1860
 
#20 0x00007f44e0239b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#21 0x00007f44de4ef95d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112



 Comments   
Comment by Elena Stepanova [ 2017-08-31 ]

It could also happen on server shutdown rather than on plugin uninstallation. The stack trace below is from 10.1.10; I didn't re-check yet if the problem still exists on the current versions.

10.1.10 non-debug build

 
2017-08-31  5:21:59 140412161328896 [Note] InnoDB: FTS optimize thread exiting.
 
2017-08-31  5:21:59 140412890978048 [Note] InnoDB: Starting shutdown...
 
170831  5:22:59 [ERROR] 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.
 
 
 
To report this bug, see http://kb.askmonty.org/en/reporting-bugs
 
 
 
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.
 
 
 
Server version: 10.1.10-MariaDB-log
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=1
 
max_threads=153
 
thread_count=0
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467105 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0x0
 
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 = 0x0 thread_stack 0x48000
 
mysys/stacktrace.c:247(my_print_stacktrace)[0x55796957c42b]
 
sql/signal_handler.cc:160(handle_fatal_signal)[0x5579690ddb05]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330)[0x7fb46ba03330]
 
/lib/x86_64-linux-gnu/libpthread.so.0(pthread_cond_wait+0xc4)[0x7fb46b9ff404]
 
psi/mysql_thread.h:1165(inline_mysql_cond_wait)[0x557968edc04f]
 
sql/mysqld.cc:6027(mysqld_main(int, char**))[0x557968ee656a]
 
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)[0x7fb46b041f45]
 
/home/travis/build/elenst/mariadb-tests/old/bin/mysqld(+0x3b7f9d)[0x557968ed9f9d]
 
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.
 
Writing a core file
 
Aborted (core dumped)
 
# 2017-08-31T05:23:37 [23507] datadir is /home/travis/build/elenst/mariadb-tests/logs/current1_1/data/
 
# 2017-08-31T05:23:37 [23507] binary is /home/travis/build/elenst/mariadb-tests/old/bin/mysqld
 
# 2017-08-31T05:23:37 [23507] bindir is /home/travis/build/elenst/mariadb-tests/old/bin
 
# 2017-08-31T05:23:37 [23507] core is /home/travis/build/elenst/mariadb-tests/logs/current1_1/data/core
 
61	../nptl/sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
 
1134	/home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h: No such file or directory.
 
# 2017-08-31T05:23:38 [23507] [New LWP 23611]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23612]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23615]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23613]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23614]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23616]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23617]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23618]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23619]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23620]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23622]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23621]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23628]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23623]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23630]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23635]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23629]
 
# 2017-08-31T05:23:38 [23507] [New LWP 23640]
 
# 2017-08-31T05:23:38 [23507] [Thread debugging using libthread_db enabled]
 
# 2017-08-31T05:23:38 [23507] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
 
# 2017-08-31T05:23:38 [23507] Core was generated by `/home/travis/build/elenst/mariadb-tests/old/bin/mysqld --no-defaults --basedir='.
 
# 2017-08-31T05:23:38 [23507] Program terminated with signal SIGABRT, Aborted.
 
# 2017-08-31T05:23:38 [23507] #0  0x00007fb46ba00611 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
 
# 2017-08-31T05:23:38 [23507] #0  0x00007fb46ba00611 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
 
# 2017-08-31T05:23:38 [23507] #1  0x00005579690ddb3f in handle_fatal_signal (sig=6) at /home/buildbot/buildbot/build/sql/signal_handler.cc:273
 
# 2017-08-31T05:23:38 [23507] #2  <signal handler called>
 
# 2017-08-31T05:23:38 [23507] #3  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
 
# 2017-08-31T05:23:38 [23507] #4  0x0000557968edc04f in inline_mysql_cond_wait (mutex=0x557969e0b040 <LOCK_thread_count>, that=0x557969e0a980 <COND_thread_count>, src_file=<optimized out>, src_line=<optimized out>) at /home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h:1165
 
# 2017-08-31T05:23:38 [23507] #5  inline_mysql_cond_wait (src_line=src_line@entry=6028, src_file=0x55796962f168 "/home/buildbot/buildbot/build/sql/mysqld.cc", mutex=0x557969e0b040 <LOCK_thread_count>, that=0x557969e0a980 <COND_thread_count>) at /home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h:1134
 
# 2017-08-31T05:23:38 [23507] #6  0x0000557968ee656a in mysqld_main (argc=23, argv=0x7fb46a42b4b8) at /home/buildbot/buildbot/build/sql/mysqld.cc:6028
 
# 2017-08-31T05:23:38 [23507] #7  0x00007fb46b041f45 in __libc_start_main (main=0x557968ec3f70 <main(int, char**)>, argc=23, argv=0x7ffd5edbfe28, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd5edbfe18) at libc-start.c:287
 
# 2017-08-31T05:23:38 [23507] #8  0x0000557968ed9f9d in _start ()
 
# 2017-08-31T05:23:38 [23507] #5  inline_mysql_cond_wait (src_line=src_line@entry=6028, src_file=0x55796962f168 "/home/buildbot/buildbot/build/sql/mysqld.cc", mutex=0x557969e0b040 <LOCK_thread_count>, that=0x557969e0a980 <COND_thread_count>) at /home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h:1134
 
# 2017-08-31T05:23:38 [23507] 1129	in /home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h
 
61	../nptl/sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
 
# 2017-08-31T05:23:40 [23507] [New LWP 23611]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23612]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23615]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23613]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23614]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23616]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23617]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23618]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23619]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23620]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23622]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23621]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23628]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23623]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23630]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23635]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23629]
 
# 2017-08-31T05:23:40 [23507] [New LWP 23640]
 
# 2017-08-31T05:23:40 [23507] [Thread debugging using libthread_db enabled]
 
# 2017-08-31T05:23:40 [23507] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
 
# 2017-08-31T05:23:40 [23507] Core was generated by `/home/travis/build/elenst/mariadb-tests/old/bin/mysqld --no-defaults --basedir='.
 
# 2017-08-31T05:23:40 [23507] Program terminated with signal SIGABRT, Aborted.
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46ba00611 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 18 (Thread 0x7fb46c7d1700 (LWP 23640)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46b1158d3 in select () at ../sysdeps/unix/syscall-template.S:81
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a621f in os_thread_sleep (tm=tm@entry=100000) at /home/buildbot/buildbot/build/storage/xtradb/os/os0thread.cc:285
 
# 2017-08-31T05:23:40 [23507] #2  0x000055796928611e in logs_empty_and_mark_files_at_shutdown () at /home/buildbot/buildbot/build/storage/xtradb/log/log0log.cc:3560
 
# 2017-08-31T05:23:40 [23507] #3  0x000055796931f7e5 in innobase_shutdown_for_mysql () at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:3162
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796922d405 in innobase_end (hton=<optimized out>, type=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/handler/ha_innodb.cc:4242
 
# 2017-08-31T05:23:40 [23507] #5  innobase_end (hton=<optimized out>, type=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/handler/ha_innodb.cc:4216
 
# 2017-08-31T05:23:40 [23507] #6  0x00005579690dff44 in ha_finalize_handlerton (plugin=0x7fb46a62c680) at /home/buildbot/buildbot/build/sql/handler.cc:452
 
# 2017-08-31T05:23:40 [23507] #7  0x0000557968f7a179 in plugin_deinitialize (plugin=0x7fb46a62c680, ref_check=ref_check@entry=true) at /home/buildbot/buildbot/build/sql/sql_plugin.cc:1209
 
# 2017-08-31T05:23:40 [23507] #8  0x0000557968f7e96e in reap_plugins () at /home/buildbot/buildbot/build/sql/sql_plugin.cc:1287
 
# 2017-08-31T05:23:40 [23507] #9  0x0000557968f7f620 in plugin_shutdown () at /home/buildbot/buildbot/build/sql/sql_plugin.cc:1940
 
# 2017-08-31T05:23:40 [23507] #10 0x0000557968edc305 in clean_up (print_message=print_message@entry=true) at /home/buildbot/buildbot/build/sql/mysqld.cc:2120
 
# 2017-08-31T05:23:40 [23507] #11 0x0000557968edd571 in clean_up (print_message=true) at /home/buildbot/buildbot/build/sql/mysqld.cc:2089
 
# 2017-08-31T05:23:40 [23507] #12 unireg_end () at /home/buildbot/buildbot/build/sql/mysqld.cc:2001
 
# 2017-08-31T05:23:40 [23507] #13 0x0000557968ee1643 in kill_server (sig_ptr=0x0) at /home/buildbot/buildbot/build/sql/mysqld.cc:1929
 
# 2017-08-31T05:23:40 [23507] #14 0x0000557968ee197e in kill_server_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/sql/mysqld.cc:1952
 
# 2017-08-31T05:23:40 [23507] #15 0x00007fb46b9fb184 in start_thread (arg=0x7fb46c7d1700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #16 0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 17 (Thread 0x7fb442ffc700 (LWP 23629)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46b1158d3 in select () at ../sysdeps/unix/syscall-template.S:81
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a621f in os_thread_sleep (tm=tm@entry=100000) at /home/buildbot/buildbot/build/storage/xtradb/os/os0thread.cc:285
 
# 2017-08-31T05:23:40 [23507] #2  0x000055796939d32a in buf_flush_page_cleaner_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/buf/buf0flu.cc:2825
 
# 2017-08-31T05:23:40 [23507] #3  0x00007fb46b9fb184 in start_thread (arg=0x7fb442ffc700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #4  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 16 (Thread 0x7fb46c863700 (LWP 23635)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46ba030c1 in do_sigwait (sig=0x7fb46c862d50, set=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/../../../../../sysdeps/unix/sysv/linux/sigwait.c:60
 
# 2017-08-31T05:23:40 [23507] #1  __sigwait (set=0x7fb46c862dc0, sig=0x7fb46c862d50) at ../nptl/sysdeps/unix/sysv/linux/../../../../../sysdeps/unix/sysv/linux/sigwait.c:97
 
# 2017-08-31T05:23:40 [23507] #2  0x0000557968edce3f in signal_hand (arg=<optimized out>) at /home/buildbot/buildbot/build/sql/mysqld.cc:3475
 
# 2017-08-31T05:23:40 [23507] #3  0x00007fb46b9fb184 in start_thread (arg=0x7fb46c863700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #4  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 15 (Thread 0x7fb4427fb700 (LWP 23630)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46b1158d3 in select () at ../sysdeps/unix/syscall-template.S:81
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a621f in os_thread_sleep (tm=tm@entry=1000000) at /home/buildbot/buildbot/build/storage/xtradb/os/os0thread.cc:285
 
# 2017-08-31T05:23:40 [23507] #2  0x000055796939dd78 in page_cleaner_sleep_if_needed (next_loop_time=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/buf/buf0flu.cc:2644
 
# 2017-08-31T05:23:40 [23507] #3  buf_flush_lru_manager_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/buf/buf0flu.cc:2912
 
# 2017-08-31T05:23:40 [23507] #4  0x00007fb46b9fb184 in start_thread (arg=0x7fb4427fb700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 14 (Thread 0x7fb447ff6700 (LWP 23623)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f2e0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=9, message1=message1@entry=0x7fb447ff5e20, message2=message2@entry=0x7fb447ff5e30, type=type@entry=0x7fb447ff5e40, space_id=space_id@entry=0x7fb447ff5e50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=9) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb447ff6700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 13 (Thread 0x7fb4437fd700 (LWP 23628)):
 
# 2017-08-31T05:23:40 [23507] #0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a4bfb in os_cond_wait (fast_mutex=0x7fb46a770500, cond=0x7fb46a770540) at /home/buildbot/buildbot/build/storage/xtradb/os/os0sync.cc:214
 
# 2017-08-31T05:23:40 [23507] #2  os_event_wait_low (event=0x7fb46a770500, reset_sig_count=<optimized out>, reset_sig_count@entry=0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0sync.cc:592
 
# 2017-08-31T05:23:40 [23507] #3  0x000055796931720c in srv_master_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0srv.cc:3211
 
# 2017-08-31T05:23:40 [23507] #4  0x00007fb46b9fb184 in start_thread (arg=0x7fb4437fd700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 12 (Thread 0x7fb448ff8700 (LWP 23621)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f2e0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=7, message1=message1@entry=0x7fb448ff7e20, message2=message2@entry=0x7fb448ff7e30, type=type@entry=0x7fb448ff7e40, space_id=space_id@entry=0x7fb448ff7e50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=7) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb448ff8700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 11 (Thread 0x7fb4487f7700 (LWP 23622)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f2e0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=8, message1=message1@entry=0x7fb4487f6e20, message2=message2@entry=0x7fb4487f6e30, type=type@entry=0x7fb4487f6e40, space_id=space_id@entry=0x7fb4487f6e50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=8) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb4487f7700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 10 (Thread 0x7fb4497f9700 (LWP 23620)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f2e0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=6, message1=message1@entry=0x7fb4497f8e20, message2=message2@entry=0x7fb4497f8e30, type=type@entry=0x7fb4497f8e40, space_id=space_id@entry=0x7fb4497f8e50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=6) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb4497f9700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 9 (Thread 0x7fb449ffa700 (LWP 23619)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f1a0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=5, message1=message1@entry=0x7fb449ff9e20, message2=message2@entry=0x7fb449ff9e30, type=type@entry=0x7fb449ff9e40, space_id=space_id@entry=0x7fb449ff9e50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=5) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb449ffa700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 8 (Thread 0x7fb44a7fb700 (LWP 23618)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f1a0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=4, message1=message1@entry=0x7fb44a7fae20, message2=message2@entry=0x7fb44a7fae30, type=type@entry=0x7fb44a7fae40, space_id=space_id@entry=0x7fb44a7fae50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=4) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb44a7fb700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 7 (Thread 0x7fb44affc700 (LWP 23617)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f1a0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=3, message1=message1@entry=0x7fb44affbe20, message2=message2@entry=0x7fb44affbe30, type=type@entry=0x7fb44affbe40, space_id=space_id@entry=0x7fb44affbe50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=3) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb44affc700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 6 (Thread 0x7fb44b7fd700 (LWP 23616)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f1a0) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=2, message1=message1@entry=0x7fb44b7fce20, message2=message2@entry=0x7fb44b7fce30, type=type@entry=0x7fb44b7fce40, space_id=space_id@entry=0x7fb44b7fce50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=2) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb44b7fd700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 5 (Thread 0x7fb44c7ff700 (LWP 23614)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f290) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=0, message1=message1@entry=0x7fb44c7fee20, message2=message2@entry=0x7fb44c7fee30, type=type@entry=0x7fb44c7fee40, space_id=space_id@entry=0x7fb44c7fee50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=0) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb44c7ff700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 4 (Thread 0x7fb4583ff700 (LWP 23613)):
 
# 2017-08-31T05:23:40 [23507] #0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579694a48ff in inline_mysql_cond_timedwait (abstime=0x7fb4583fed90, mutex=0x55796a673dc0 <LOCK_checkpoint>, that=0x55796a673e00 <COND_checkpoint>, src_file=<optimized out>, src_line=<optimized out>) at /home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h:1202
 
# 2017-08-31T05:23:40 [23507] #2  my_service_thread_sleep (control=control@entry=0x557969da1c00 <checkpoint_control>, sleep_time=<optimized out>) at /home/buildbot/buildbot/build/storage/maria/ma_servicethread.c:118
 
# 2017-08-31T05:23:40 [23507] #3  0x000055796949cf3f in ma_checkpoint_background (arg=0x1e) at /home/buildbot/buildbot/build/storage/maria/ma_checkpoint.c:711
 
# 2017-08-31T05:23:40 [23507] #4  0x00007fb46b9fb184 in start_thread (arg=0x7fb4583ff700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 3 (Thread 0x7fb44bffe700 (LWP 23615)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46c48a58a in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579692a38bd in os_aio_linux_collect (seg_size=256, segment=<optimized out>, array=0x7fb46a48f150) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5373
 
# 2017-08-31T05:23:40 [23507] #2  os_aio_linux_handle (global_seg=global_seg@entry=1, message1=message1@entry=0x7fb44bffde20, message2=message2@entry=0x7fb44bffde30, type=type@entry=0x7fb44bffde40, space_id=space_id@entry=0x7fb44bffde50) at /home/buildbot/buildbot/build/storage/xtradb/os/os0file.cc:5526
 
# 2017-08-31T05:23:40 [23507] #3  0x00005579693ea17a in fil_aio_wait (segment=segment@entry=1) at /home/buildbot/buildbot/build/storage/xtradb/fil/fil0fil.cc:5998
 
# 2017-08-31T05:23:40 [23507] #4  0x000055796931b2c0 in io_handler_thread (arg=<optimized out>) at /home/buildbot/buildbot/build/storage/xtradb/srv/srv0start.cc:542
 
# 2017-08-31T05:23:40 [23507] #5  0x00007fb46b9fb184 in start_thread (arg=0x7fb44bffe700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #6  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 2 (Thread 0x7fb46a3ff700 (LWP 23612)):
 
# 2017-08-31T05:23:40 [23507] #0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
 
# 2017-08-31T05:23:40 [23507] #1  0x0000557969580d37 in inline_mysql_cond_timedwait (abstime=0x7fb46a3fee10, that=<optimized out>, mutex=<optimized out>, src_file=<optimized out>, src_line=<optimized out>) at /home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h:1202
 
# 2017-08-31T05:23:40 [23507] #2  timer_handler (arg=<optimized out>) at /home/buildbot/buildbot/build/mysys/thr_timer.c:292
 
# 2017-08-31T05:23:40 [23507] #3  0x00007fb46b9fb184 in start_thread (arg=0x7fb46a3ff700) at pthread_create.c:312
 
# 2017-08-31T05:23:40 [23507] #4  0x00007fb46b11dffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
 
# 2017-08-31T05:23:40 [23507] 
# 2017-08-31T05:23:40 [23507] Thread 1 (Thread 0x7fb46c8957c0 (LWP 23611)):
 
# 2017-08-31T05:23:40 [23507] #0  0x00007fb46ba00611 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
 
# 2017-08-31T05:23:40 [23507] #1  0x00005579690ddb3f in handle_fatal_signal (sig=6) at /home/buildbot/buildbot/build/sql/signal_handler.cc:273
 
# 2017-08-31T05:23:40 [23507] #2  <signal handler called>
 
# 2017-08-31T05:23:40 [23507] #3  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
 
# 2017-08-31T05:23:40 [23507] #4  0x0000557968edc04f in inline_mysql_cond_wait (mutex=0x557969e0b040 <LOCK_thread_count>, that=0x557969e0a980 <COND_thread_count>, src_file=<optimized out>, src_line=<optimized out>) at /home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h:1165
 
# 2017-08-31T05:23:40 [23507] #5  inline_mysql_cond_wait (src_line=src_line@entry=6028, src_file=0x55796962f168 "/home/buildbot/buildbot/build/sql/mysqld.cc", mutex=0x557969e0b040 <LOCK_thread_count>, that=0x557969e0a980 <COND_thread_count>) at /home/buildbot/buildbot/build/include/mysql/psi/mysql_thread.h:1134
 
# 2017-08-31T05:23:40 [23507] #6  0x0000557968ee656a in mysqld_main (argc=23, argv=0x7fb46a42b4b8) at /home/buildbot/buildbot/build/sql/mysqld.cc:6028
 
# 2017-08-31T05:23:40 [23507] #7  0x00007fb46b041f45 in __libc_start_main (main=0x557968ec3f70 <main(int, char**)>, argc=23, argv=0x7ffd5edbfe28, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd5edbfe18) at libc-start.c:287
 
# 2017-08-31T05:23:40 [23507] #8  0x0000557968ed9f9d in _start ()

10.0.14 was also affected.

Comment by Elena Stepanova [ 2018-02-20 ]

According to the question at stackoverflow, 10.2.13 started hanging upon bootstrap while 10.2.11 was not. I was able to reproduce the hang by re-running bootstrap in a loop:

10.2.13 relwithdebinfo

 
Thread 1 (Thread 0x7f7cb604db80 (LWP 22856)):
 
#0  0x00007f7cb5c3d7dd in nanosleep () at ../sysdeps/unix/syscall-template.S:84
 
#1  0x00005603ffcc690c in os_thread_sleep (tm=tm@entry=100000) at /data/src/10.2/storage/innobase/os/os0thread.cc:230
 
#2  0x00005603ffca80b4 in logs_empty_and_mark_files_at_shutdown () at /data/src/10.2/storage/innobase/log/log0log.cc:1998
 
#3  0x00005603ffd52bb5 in innodb_shutdown () at /data/src/10.2/storage/innobase/srv/srv0start.cc:2856
 
#4  0x00005603ffc480de in innobase_end () at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4491
 
#5  0x00005603ffa3a2ab in ha_finalize_handlerton (plugin=0x560401b98b18) at /data/src/10.2/sql/handler.cc:459
 
#6  0x00005603ff8b4379 in plugin_deinitialize (plugin=0x560401b98b18, ref_check=ref_check@entry=true) at /data/src/10.2/sql/sql_plugin.cc:1219
 
#7  0x00005603ff8b79fe in reap_plugins () at /data/src/10.2/sql/sql_plugin.cc:1295
 
#8  0x00005603ff8b84e5 in plugin_shutdown () at /data/src/10.2/sql/sql_plugin.cc:1953
 
#9  0x00005603ff81488c in clean_up (print_message=<optimized out>) at /data/src/10.2/sql/mysqld.cc:2218
 
#10 0x00005603ff817b92 in clean_up (print_message=<optimized out>) at /data/src/10.2/sql/mysqld.cc:2137
 
#11 unireg_abort (exit_code=0) at /data/src/10.2/sql/mysqld.cc:2137
 
#12 0x00005603ff81f8a7 in mysqld_main (argc=11, argv=0x560401b50fd0) at /data/src/10.2/sql/mysqld.cc:5975
 
#13 0x00007f7cb3f522b1 in __libc_start_main () from /lib/x86_64-linux-gnu/libc.so.6
 
#14 0x00005603ff812c1a in _start ()

It looks the same as the problem reported here.

10.2 27ea2963fc debug

 
Thread 1 (Thread 0x7f4a93a1ab80 (LWP 29539)):
 
#0  0x00007f4a9360a7dd in nanosleep () at ../sysdeps/unix/syscall-template.S:84
 
#1  0x0000556df6e8cee3 in os_thread_sleep (tm=100000) at /data/src/10.2/storage/innobase/os/os0thread.cc:230
 
#2  0x0000556df6e61973 in logs_empty_and_mark_files_at_shutdown () at /data/src/10.2/storage/innobase/log/log0log.cc:1996
 
#3  0x0000556df6f815a1 in innodb_shutdown () at /data/src/10.2/storage/innobase/srv/srv0start.cc:2855
 
#4  0x0000556df6dc5ab4 in innobase_end () at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4483
 
#5  0x0000556df6ab8e2f in ha_finalize_handlerton (plugin=0x556df88299a0) at /data/src/10.2/sql/handler.cc:459
 
#6  0x0000556df685e9f9 in plugin_deinitialize (plugin=0x556df88299a0, ref_check=true) at /data/src/10.2/sql/sql_plugin.cc:1219
 
#7  0x0000556df685ee66 in reap_plugins () at /data/src/10.2/sql/sql_plugin.cc:1295
 
#8  0x0000556df6860ead in plugin_shutdown () at /data/src/10.2/sql/sql_plugin.cc:1953
 
#9  0x0000556df6762e46 in clean_up (print_message=false) at /data/src/10.2/sql/mysqld.cc:2218
 
#10 0x0000556df6762b67 in unireg_abort (exit_code=0) at /data/src/10.2/sql/mysqld.cc:2137
 
#11 0x0000556df676a74b in mysqld_main (argc=11, argv=0x556df87d47d8) at /data/src/10.2/sql/mysqld.cc:5975
 
#12 0x0000556df675f1d0 in main (argc=10, argv=0x7ffe78a7a8c8) at /data/src/10.2/sql/main.cc:25

same occurrence, all threads

 
[Thread debugging using libthread_db enabled]
 
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
 
0x00007f4a9360a7dd in nanosleep () at ../sysdeps/unix/syscall-template.S:84
 
 
 
Thread 15 (Thread 0x7f4a91802700 (LWP 29542)):
 
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
 
#1  0x0000556df7221250 in safe_cond_timedwait (cond=0x556df8669f80 <COND_timer>, mp=0x556df8669ec0 <LOCK_timer>, abstime=0x7f4a91801f00, file=0x556df7592cf0 "/data/src/10.2/include/mysql/psi/mysql_thread.h", line=1186) at /data/src/10.2/mysys/thr_mutex.c:545
 
#2  0x0000556df7222211 in inline_mysql_cond_timedwait (that=0x556df8669f80 <COND_timer>, mutex=0x556df8669ec0 <LOCK_timer>, abstime=0x7f4a91801f00, src_file=0x556df7592d20 "/data/src/10.2/mysys/thr_timer.c", src_line=292) at /data/src/10.2/include/mysql/psi/mysql_thread.h:1186
 
#3  0x0000556df7222cc8 in timer_handler (arg=0x0) at /data/src/10.2/mysys/thr_timer.c:292
 
#4  0x00007f4a93601494 in start_thread (arg=0x7f4a91802700) at pthread_create.c:333
 
#5  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 14 (Thread 0x7f4a30399700 (LWP 29544)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a30398c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a30398c40, m1=0x7f4a30398ce8, m2=0x7f4a30398cf0, request=0x7f4a30398d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=0, m1=0x7f4a30398ce8, m2=0x7f4a30398cf0, request=0x7f4a30398d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=0, m1=0x7f4a30398ce8, m2=0x7f4a30398cf0, request=0x7f4a30398d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=0) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8650fc0 <n>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a30399700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 13 (Thread 0x7f4a2fb98700 (LWP 29545)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2fb97c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2fb97c40, m1=0x7f4a2fb97ce8, m2=0x7f4a2fb97cf0, request=0x7f4a2fb97d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=1, m1=0x7f4a2fb97ce8, m2=0x7f4a2fb97cf0, request=0x7f4a2fb97d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=1, m1=0x7f4a2fb97ce8, m2=0x7f4a2fb97cf0, request=0x7f4a2fb97d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=1) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8650fc8 <n+8>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2fb98700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 12 (Thread 0x7f4a2f397700 (LWP 29546)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2f396c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2f396c40, m1=0x7f4a2f396ce8, m2=0x7f4a2f396cf0, request=0x7f4a2f396d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=2, m1=0x7f4a2f396ce8, m2=0x7f4a2f396cf0, request=0x7f4a2f396d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=2, m1=0x7f4a2f396ce8, m2=0x7f4a2f396cf0, request=0x7f4a2f396d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=2) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8650fd0 <n+16>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2f397700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 11 (Thread 0x7f4a2eb96700 (LWP 29547)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2eb95c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2eb95c40, m1=0x7f4a2eb95ce8, m2=0x7f4a2eb95cf0, request=0x7f4a2eb95d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=3, m1=0x7f4a2eb95ce8, m2=0x7f4a2eb95cf0, request=0x7f4a2eb95d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=3, m1=0x7f4a2eb95ce8, m2=0x7f4a2eb95cf0, request=0x7f4a2eb95d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=3) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8650fd8 <n+24>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2eb96700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 10 (Thread 0x7f4a2e395700 (LWP 29548)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2e394c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2e394c40, m1=0x7f4a2e394ce8, m2=0x7f4a2e394cf0, request=0x7f4a2e394d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=4, m1=0x7f4a2e394ce8, m2=0x7f4a2e394cf0, request=0x7f4a2e394d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=4, m1=0x7f4a2e394ce8, m2=0x7f4a2e394cf0, request=0x7f4a2e394d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=4) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8650fe0 <n+32>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2e395700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 9 (Thread 0x7f4a2db94700 (LWP 29549)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2db93c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2db93c40, m1=0x7f4a2db93ce8, m2=0x7f4a2db93cf0, request=0x7f4a2db93d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=5, m1=0x7f4a2db93ce8, m2=0x7f4a2db93cf0, request=0x7f4a2db93d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=5, m1=0x7f4a2db93ce8, m2=0x7f4a2db93cf0, request=0x7f4a2db93d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=5) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8650fe8 <n+40>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2db94700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 8 (Thread 0x7f4a2d393700 (LWP 29550)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2d392c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2d392c40, m1=0x7f4a2d392ce8, m2=0x7f4a2d392cf0, request=0x7f4a2d392d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=6, m1=0x7f4a2d392ce8, m2=0x7f4a2d392cf0, request=0x7f4a2d392d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=6, m1=0x7f4a2d392ce8, m2=0x7f4a2d392cf0, request=0x7f4a2d392d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=6) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8650ff0 <n+48>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2d393700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 7 (Thread 0x7f4a2cb92700 (LWP 29551)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2cb91c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2cb91c40, m1=0x7f4a2cb91ce8, m2=0x7f4a2cb91cf0, request=0x7f4a2cb91d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=7, m1=0x7f4a2cb91ce8, m2=0x7f4a2cb91cf0, request=0x7f4a2cb91d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=7, m1=0x7f4a2cb91ce8, m2=0x7f4a2cb91cf0, request=0x7f4a2cb91d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=7) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8650ff8 <n+56>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2cb92700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 6 (Thread 0x7f4a2c391700 (LWP 29552)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2c390c40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2c390c40, m1=0x7f4a2c390ce8, m2=0x7f4a2c390cf0, request=0x7f4a2c390d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=8, m1=0x7f4a2c390ce8, m2=0x7f4a2c390cf0, request=0x7f4a2c390d20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=8, m1=0x7f4a2c390ce8, m2=0x7f4a2c390cf0, request=0x7f4a2c390d20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=8) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8651000 <n+64>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2c391700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 5 (Thread 0x7f4a2bb90700 (LWP 29553)):
 
#0  0x00007f4a933f86ea in ?? () from /lib/x86_64-linux-gnu/libaio.so.1
 
#1  0x0000556df6e7fea4 in LinuxAIOHandler::collect (this=0x7f4a2bb8fc40) at /data/src/10.2/storage/innobase/os/os0file.cc:1893
 
#2  0x0000556df6e803b2 in LinuxAIOHandler::poll (this=0x7f4a2bb8fc40, m1=0x7f4a2bb8fce8, m2=0x7f4a2bb8fcf0, request=0x7f4a2bb8fd20) at /data/src/10.2/storage/innobase/os/os0file.cc:2038
 
#3  0x0000556df6e80512 in os_aio_linux_handler (global_segment=9, m1=0x7f4a2bb8fce8, m2=0x7f4a2bb8fcf0, request=0x7f4a2bb8fd20) at /data/src/10.2/storage/innobase/os/os0file.cc:2092
 
#4  0x0000556df6e8507d in os_aio_handler (segment=9, m1=0x7f4a2bb8fce8, m2=0x7f4a2bb8fcf0, request=0x7f4a2bb8fd20) at /data/src/10.2/storage/innobase/os/os0file.cc:5720
 
#5  0x0000556df70ceb1e in fil_aio_wait (segment=9) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5330
 
#6  0x0000556df6f7a0a1 in io_handler_thread (arg=0x556df8651008 <n+72>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:342
 
#7  0x00007f4a93601494 in start_thread (arg=0x7f4a2bb90700) at pthread_create.c:333
 
#8  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 4 (Thread 0x7f4a2b38f700 (LWP 29554)):
 
#0  0x00007f4a9360a7dd in nanosleep () at ../sysdeps/unix/syscall-template.S:84
 
#1  0x0000556df6e8cee3 in os_thread_sleep (tm=10000) at /data/src/10.2/storage/innobase/os/os0thread.cc:230
 
#2  0x0000556df705b748 in buf_flush_page_cleaner_close () at /data/src/10.2/storage/innobase/buf/buf0flu.cc:2754
 
#3  0x0000556df705d2be in buf_flush_page_cleaner_coordinator () at /data/src/10.2/storage/innobase/buf/buf0flu.cc:3466
 
#4  0x00007f4a93601494 in start_thread (arg=0x7f4a2b38f700) at pthread_create.c:333
 
#5  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 3 (Thread 0x7f4a2ab8e700 (LWP 29555)):
 
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
 
#1  0x0000556df6e8cbc8 in os_event::wait (this=0x556dfb81f280) at /data/src/10.2/storage/innobase/os/os0event.cc:166
 
#2  0x0000556df6e8c5d7 in os_event::wait_low (this=0x556dfb81f280, reset_sig_count=5) at /data/src/10.2/storage/innobase/os/os0event.cc:336
 
#3  0x0000556df6e8c97d in os_event_wait_low (event=0x556dfb81f280, reset_sig_count=0) at /data/src/10.2/storage/innobase/os/os0event.cc:535
 
#4  0x0000556df705d40d in buf_flush_page_cleaner_worker (arg=0x0) at /data/src/10.2/storage/innobase/buf/buf0flu.cc:3507
 
#5  0x00007f4a93601494 in start_thread (arg=0x7f4a2ab8e700) at pthread_create.c:333
 
#6  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 2 (Thread 0x7f4a90093700 (LWP 29572)):
 
#0  do_sigwait (set=<optimized out>, set@entry=0x7f4a90092e80, sig=sig@entry=0x7f4a90092e50) at ../sysdeps/unix/sysv/linux/sigwait.c:64
 
#1  0x00007f4a9360aced in __sigwait (set=0x7f4a90092e80, sig=0x7f4a90092e50) at ../sysdeps/unix/sysv/linux/sigwait.c:96
 
#2  0x0000556df6765a53 in signal_hand (arg=0x0) at /data/src/10.2/sql/mysqld.cc:3505
 
#3  0x00007f4a93601494 in start_thread (arg=0x7f4a90093700) at pthread_create.c:333
 
#4  0x00007f4a919e793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Thread 1 (Thread 0x7f4a93a1ab80 (LWP 29539)):
 
#0  0x00007f4a9360a7dd in nanosleep () at ../sysdeps/unix/syscall-template.S:84
 
#1  0x0000556df6e8cee3 in os_thread_sleep (tm=100000) at /data/src/10.2/storage/innobase/os/os0thread.cc:230
 
#2  0x0000556df6e61973 in logs_empty_and_mark_files_at_shutdown () at /data/src/10.2/storage/innobase/log/log0log.cc:1996
 
#3  0x0000556df6f815a1 in innodb_shutdown () at /data/src/10.2/storage/innobase/srv/srv0start.cc:2855
 
#4  0x0000556df6dc5ab4 in innobase_end () at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4483
 
#5  0x0000556df6ab8e2f in ha_finalize_handlerton (plugin=0x556df88299a0) at /data/src/10.2/sql/handler.cc:459
 
#6  0x0000556df685e9f9 in plugin_deinitialize (plugin=0x556df88299a0, ref_check=true) at /data/src/10.2/sql/sql_plugin.cc:1219
 
#7  0x0000556df685ee66 in reap_plugins () at /data/src/10.2/sql/sql_plugin.cc:1295
 
#8  0x0000556df6860ead in plugin_shutdown () at /data/src/10.2/sql/sql_plugin.cc:1953
 
#9  0x0000556df6762e46 in clean_up (print_message=false) at /data/src/10.2/sql/mysqld.cc:2218
 
#10 0x0000556df6762b67 in unireg_abort (exit_code=0) at /data/src/10.2/sql/mysqld.cc:2137
 
#11 0x0000556df676a74b in mysqld_main (argc=11, argv=0x556df87d47d8) at /data/src/10.2/sql/mysqld.cc:5975
 
#12 0x0000556df675f1d0 in main (argc=10, argv=0x7ffe78a7a8c8) at /data/src/10.2/sql/main.cc:25

I can reproduce it reasonably well on my local machine by running this on 10.2.13 release (or on the current build):

for i in 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 ; do echo "Running trial no.$i" && echo "" && rm -rf data/* && mkdir data/mysql && echo "use mysql;" > ./use.sql && cat ./use.sql  share/mysql_system_tables.sql share/mysql_performance_tables.sql share/mysql_system_tables_data.sql share/fill_help_tables.sql share/maria_add_gis_sp_bootstrap.sql | bin/mysqld --bootstrap --basedir=`pwd` --datadir=`pwd`/data  --innodb-buffer-pool-size=1G   && echo "" && echo "Trial no.$i finished" && sleep 1 ; done

but only on a busy machine (by CPU-bound activities as it seems). Could not reproduce on an idle machine, couldn't reproduce on 10.2.12. innodb_buffer_pool_size seems to be important, or the number of instances is.

So, even if it's the same bug as initially reported, something seems to have changed in 10.2.13 to make it happen considerably more often and/or in new circumstances.

The reporter at stackoverflow also says that it started happening between 10.2.11 and 10.2.13.

Comment by Marko Mäkelä [ 2018-03-09 ]

The 10.0, 10.1 shutdown hang is due to a bug outside InnoDB:

diff --git a/sql/handler.cc b/sql/handler.cc
 
index 07dc0cf04a9..631a9abbb54 100644
 
--- a/sql/handler.cc
 
+++ b/sql/handler.cc
 
@@ -786,7 +786,9 @@ static my_bool closecon_handlerton(THD *thd, plugin_ref plugin,
 
 */
 
 void ha_close_connection(THD* thd)
 
 {
 
-  plugin_foreach(thd, closecon_handlerton, MYSQL_STORAGE_ENGINE_PLUGIN, 0);
 
+  plugin_foreach_with_mask(thd, closecon_handlerton,
 
+			   MYSQL_STORAGE_ENGINE_PLUGIN,
 
+			   PLUGIN_IS_DELETED|PLUGIN_IS_READY, 0);
 
 }
 
 
 static my_bool kill_handlerton(THD *thd, plugin_ref plugin,

This was fixed in 10.2 as part of MDEV-14648. With the above fix backported, the hang goes away.
Due to this bug, the test innodb.innodb_uninstall took 126 seconds to run (with two hung shutdowns, aborted by the 60-second timeout) instead of 9 seconds.

I will keep this ticket open for the 10.2 bootstrap hang.

Comment by Elena Stepanova [ 2018-03-12 ]

In fact, it happens regularly even on an idle machine. I'm getting it by simply running

scripts/mysql_install_db --no-defaults --innodb_buffer_pool_size=2G

in a loop.

Comment by Marko Mäkelä [ 2018-03-13 ]

I can repeat the bootstrap hang with 10.2 (commit 3a93ec53c1efdb511721fdb9e3bef9c3cf3bf675) as follows:

seq 1 16|while read i; do mkdir -p /mariadb/10.2-data$i/mysql && echo "use mysql;" |
 
cat - bld/scripts/mysql_system_tables.sql bld/scripts/mysql_performance_tables.sql bld/scripts/mysql_system_tables_data.sql bld/scripts/fill_help_tables.sql bld/scripts/maria_add_gis_sp_bootstrap.sql |
 
bld/sql/mysqld --lc-messages-dir=/mariadb/10.2/bld/sql/share --bootstrap --basedir=`pwd` --datadir=/mariadb/10.2-data$i --innodb-buffer-pool-size=1G&
 
done

This left 3 hung mysqld instances out of the 16. I analyzed one of them: it is waiting for buf_page_cleaner_is_active=false. Two page cleaner threads exist:

#5  0x000055dfdc0696f1 in os_event_wait_low (event=0x55dfe06b8ff0, 
    reset_sig_count=0) at /mariadb/10.2/storage/innobase/os/os0event.cc:535
 
#6  0x000055dfdc23ce95 in buf_flush_page_cleaner_worker (arg=0x0)
 
    at /mariadb/10.2/storage/innobase/buf/buf0flu.cc:3484
 
…
 
Thread 13 (Thread 0x7f9241f61700 (LWP 22112)):
 
#0  0x00007f929e10e2e0 in __GI___nanosleep (requested_time=0x7f9241f60c70, 
    remaining=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
 
#1  0x000055dfdc069c68 in os_thread_sleep (tm=10000)
 
    at /mariadb/10.2/storage/innobase/os/os0thread.cc:230
 
#2  0x000055dfdc23b265 in buf_flush_page_cleaner_close ()
 
    at /mariadb/10.2/storage/innobase/buf/buf0flu.cc:2731
 
#3  0x000055dfdc23cd37 in buf_flush_page_cleaner_coordinator ()
 
    at /mariadb/10.2/storage/innobase/buf/buf0flu.cc:3443

The worker is waiting for page_cleaner.is_requested, but the coordinator is not signalling that event while waiting for the workers to terminate. The event is signaled only once, before entering the wait loop:

	os_event_set(page_cleaner.is_requested);
 
 
 
	buf_flush_page_cleaner_close();

The signal should be moved inside the wait loop:

	while (page_cleaner.n_workers) {
 
		os_thread_sleep(10000);
 
	}

This shutdown hang should be unique to MariaDB 10.2 and later. The multiple page cleaner threads were introduced in MySQL 5.7, which was first merged to MariaDB in 10.2.2.

Comment by Marko Mäkelä [ 2018-03-13 ]

This issue mixed 2 bugs:
MDEV-14648 (UNINSTALL PLUGIN bug) was fixed in 10.0.35, 10.1.32, 10.2.14, 10.3.5.
MDEV-15554 (InnoDB shutdown hang with multiple page cleaners) was fixed in 10.2.14, 10.3.6.

Generated at Thu Feb 08 07:25:17 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.