Details
-
Bug
-
Status: Done
-
Medium
-
Resolution: Fixed
-
8.0.x, Not 5.6.x, Not 5.7.x
-
None
Description
Server started with threadpool crashes at the very end of shutdown, intermittently. An example:
[ 5%] main.percona_signal_handling_threadpool w2 [ fail ] Found warnings/errors in server log file!
Test ended at 2019-03-21 02:38:11
line
Attempting backtrace. You can use the following information to find out
^ Found warnings in /home/laurynas/percona/obj-percona-8.0-release/mysql-test/var/2/log/mysqld.1.err
ok
with example following core dump stacktraces:
Thread 3 (Thread 0x7f11b00b5700 (LWP 22330)): #0 0x00007f11c51e73ab in _Unwind_IteratePhdrCallback ([email protected]=0x7f11b00b3d40, [email protected]=64, [email protected]=0x7f11b00b3dd0) at ../../../src/libgcc/unwind-dw2-fde-dip.c:398 #1 0x00007f11c5146417 in __GI___dl_iterate_phdr ([email protected]=0x7f11c51e6ff0 <_Unwind_IteratePhdrCallback>, [email protected]=0x7f11b00b3dd0) at dl-iteratephdr.c:75 #2 0x00007f11c51e8281 in _Unwind_Find_FDE (pc=0x7f11c5114ca1 <__GI___backtrace+97>, [email protected]=0x7f11b00b3f58) at ../../../src/libgcc/unwind-dw2-fde-dip.c:469 #3 0x00007f11c51e4983 in uw_frame_state_for ([email protected]=0x7f11b00b3eb0, [email protected]=0x7f11b00b3fa0) at ../../../src/libgcc/unwind-dw2.c:1257 #4 0x00007f11c51e6898 in _Unwind_Backtrace (trace=0x7f11c5114b40 <backtrace_helper>, trace_argument=0x7f11b00b4160) at ../../../src/libgcc/unwind.inc:302 #5 0x00007f11c5114ca2 in __GI___backtrace ([email protected]=0x7f11b00b41c0, [email protected]=128) at backtrace.c:111 #6 0x0000558c8936bffd in my_print_stacktrace (stack_bottom=0x0, thread_stack=286720) at ../../percona-8.0/mysys/stacktrace.cc:258 #7 0x0000558c886641a3 in handle_fatal_signal (sig=11) at ../../percona-8.0/sql/signal_handler.cc:178 #8 <signal handler called> #9 std::__atomic_base<bool>::store (__m=std::memory_order_seq_cst, __i=true, this=0x7f11bc4ce878) at /usr/include/c++/7/bits/atomic_base.h:374 #10 std::__atomic_base<bool>::operator= (__i=true, this=0x7f11bc4ce878) at /usr/include/c++/7/bits/atomic_base.h:267 #11 std::atomic<bool>::operator= (__i=true, this=0x7f11bc4ce878) at /usr/include/c++/7/atomic:79 #12 memory_full_aggregate<PFS_memory_safe_stat, PFS_memory_shared_stat> (stat=0x7f11bc4ce878, from=0x7f11bf16c088) at ../../../percona-8.0/storage/perfschema/pfs_stat.h:1029 #13 aggregate_all_memory (alive=false, from_array=0x7f11bf169850, to_array=0x7f11bc4cc040) at ../../../percona-8.0/storage/perfschema/pfs_instr.cc:1617 #14 0x0000558c893a40b3 in aggregate_thread ([email protected]=0x7f11c2c67d80, safe_account=0x558c8b9acc80, safe_user=0x0, safe_host=0x0) at ../../../percona-8.0/storage/perfschema/pfs_instr.cc:1761 #15 0x0000558c89388e8f in pfs_delete_current_thread_v1 () at ../../../percona-8.0/storage/perfschema/pfs.cc:3385 #16 0x0000558c88646237 in worker_main ([email protected]=0x558c8ac0e600 <all_groups+1536>) at ../../percona-8.0/sql/threadpool_unix.cc:1451 #17 0x0000558c89388a3f in pfs_spawn_thread (arg=0x7f115c035980) at ../../../percona-8.0/storage/perfschema/pfs.cc:2836 #18 0x00007f11c6bc1164 in start_thread (arg=<optimized out>) at pthread_create.c:486 #19 0x00007f11c5105def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 Thread 2 (Thread 0x7f11c343b840 (LWP 21817)): #0 0x00007f11c50ff497 in munmap () at ../sysdeps/unix/syscall-template.S:78 #1 0x0000558c893997ae in pfs_free ([email protected]=0x558c8ac76640 <builtin_memory_user_errors>, size=140768, ptr=<optimized out>) at ../../../percona-8.0/storage/perfschema/pfs_global.cc:113 #2 0x0000558c89399856 in pfs_free_array ([email protected]=0x558c8ac76640 <builtin_memory_user_errors>, n=<optimized out>, [email protected]=32, ptr=<optimized out>) --Type <RET> for more, q to quit, c to continue without paging-- at ../../../percona-8.0/storage/perfschema/pfs_global.cc:177 #3 0x0000558c89394475 in PFS_error_stat::cleanup (memory_class=<optimized out>, this=0x558c8b9eb2b0) at ../../../percona-8.0/storage/perfschema/pfs_stat.h:604 #4 PFS_user_allocator::free_array (this=<optimized out>, [email protected]=0x558c8b9cfdf0) at ../../../percona-8.0/storage/perfschema/pfs_buffer_container.cc:1036 #5 0x0000558c893af80c in PFS_buffer_scalable_container<PFS_user, 128, 128, PFS_user_array, PFS_user_allocator>::cleanup (this=<optimized out>) at ../../../percona-8.0/storage/perfschema/pfs_buffer_container.h:452 #6 cleanup_user () at ../../../percona-8.0/storage/perfschema/pfs_user.cc:64 #7 0x0000558c893ac688 in cleanup_performance_schema () at ../../../percona-8.0/storage/perfschema/pfs_server.cc:284 #8 0x0000558c893acd6c in shutdown_performance_schema () at ../../../percona-8.0/storage/perfschema/pfs_server.cc:337 #9 0x0000558c8840a97c in mysqld_exit (exit_code=0) at ../../percona-8.0/sql/mysqld.cc:2060 #10 0x0000558c8841caad in mysqld_main (argc=<optimized out>, argv=<optimized out>) at ../../percona-8.0/sql/mysqld.cc:7094 #11 0x00007f11c500f09b in __libc_start_main (main=0x558c8829ca00 <main(int, char**)>, argc=7, argv=0x7fff564fb148, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff564fb138) at ../csu/libc-start.c:308 #12 0x0000558c882cb1ea in _start () Thread 1 (Thread 0x7f11b00fd700 (LWP 22300)): #0 memcpy (__len=176, __src=0x7f11c2c63d20, __dest=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/string_fortified.h:34 #1 copy_events_waits (source=0x7f11c2c63d20, dest=<optimized out>) at ../../../percona-8.0/storage/perfschema/pfs_events_waits.cc:93 #2 insert_events_waits_history_long ([email protected]=0x7f11c2c63d20) at ../../../percona-8.0/storage/perfschema/pfs_events_waits.cc:143 #3 0x0000558c8938aad8 in pfs_end_cond_wait_v1 ([email protected]=0x7f11b00fcce0) at ../../../percona-8.0/storage/perfschema/pfs.cc:4918 #4 0x0000558c88645ee0 in inline_mysql_cond_timedwait (src_file=0x558c8a0b4220 "../../percona-8.0/sql/threadpool_unix.cc", src_line=1083, abstime=0x7f11b00fccd0, mutex=0x558c8ac0e600 <all_groups+1536>, that=0x7f11b00fcd40) at ../../percona-8.0/include/mysql/psi/mysql_cond.h:226 #5 get_event (abstime=0x7f11b00fccd0, thread_group=0x558c8ac0e600 <all_groups+1536>, current_thread=0x7f11b00fcd20) at ../../percona-8.0/sql/threadpool_unix.cc:1082 #6 worker_main ([email protected]=0x558c8ac0e600 <all_groups+1536>) at ../../percona-8.0/sql/threadpool_unix.cc:1432 #7 0x0000558c89388a3f in pfs_spawn_thread (arg=0x558c8be3f400) at ../../../percona-8.0/storage/perfschema/pfs.cc:2836 #8 0x00007f11c6bc1164 in start_thread (arg=<optimized out>) at pthread_create.c:486 #9 0x00007f11c5105def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Many other stacktraces are possible. What they have in common is one threadpool worker thread which just woke up from its event wait, and the rest of the server far advanced in the shutdown (as far as in libc cleanup routines after main()).
This is caused by worker thread shutdown being asynchronuous, i.e. tp_end() calls thread_group_close() which wakes the threads to shut them down and then their shutdown proceeds asynchronuously.
