Intermittently stalled or crashing shutdown if it's issued immediately after HandlerSocket startup

Bug #1617198 reported by Laurynas Biveinis
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
Invalid
Undecided
Unassigned
5.6
Fix Released
High
Laurynas Biveinis
5.7
Invalid
Undecided
Unassigned

Bug Description

If server is shutdown immediately after HandlerSocket plugin has initialized, it may hit a race condition between worker thread initialisation, which happens asynchronously, and at some point adds threads to the server global thread list, and server shutdown, which waits for the thread count to go down to zero. This race condition may result in some worker threads not receiving kill notifications, and thus hanging the server shutdown

On 5.6 trunk:

main.handler_socket w1 [ fail ]
        Test ended at 2016-08-25 08:24:42

CURRENT_TEST: main.handler_socket
--- /mnt/workspace/percona-server-5.6-trunk/BUILD_TYPE/release/Host/ubuntu-precise-32bit/mysql-test/r/handler_socket.result 2016-08-25 14:53:53.197025000 +0300
+++ /mnt/workspace/percona-server-5.6-trunk/BUILD_TYPE/release/Host/ubuntu-precise-32bit/build/mysql-test/var/1/log/handler_socket.reject 2016-08-25 15:24:42.525025000 +0300
@@ -1,4 +1,5 @@
 call mtr.add_suppression("handlersocket: open_files_limit is too small");
 INSTALL PLUGIN handlersocket SONAME 'HANDLER_SOCKET';
 Restarting mysqld for bug 1397859 test...
+shutdown_server timeout 60 exceeded, SIGKILL sent to the server
 UNINSTALL PLUGIN handlersocket;

tags: added: ci handlersocket
summary: - Test main.handler_socket is unstable
+ Intermittently stalled shutdown if it's issued immediately after
+ HandlerSocket startup
description: updated
description: updated
tags: added: upstream
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote : Re: Intermittently stalled shutdown if it's issued immediately after HandlerSocket startup

The same race condition may also result in a crash:

Core was generated by `/home/laurynas/obj-percona-5.6-debug/sql/mysqld-debug --defaults-group-suffix=.'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 __pthread_kill (threadid=<optimized out>, signo=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:62
62 ../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
[Current thread is 1 (Thread 0x7f577a7f4700 (LWP 14317))]
#0 __pthread_kill (threadid=<optimized out>, signo=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:62
#1 0x0000000000b0ea3e in my_write_core (sig=11) at /home/laurynas/mysql-server/mysys/stacktrace.c:422
#2 0x000000000074c599 in handle_fatal_signal (sig=11) at /home/laurynas/mysql-server/sql/signal_handler.cc:236
#3 <signal handler called>
#4 0x000000000062da10 in inline_mysql_rwlock_rdlock (that=0x8, src_file=0xf591c8 "/home/laurynas/mysql-server/sql/rpl_gtid.h", src_line=347) at /home/laurynas/mysql-server/include/mysql/psi/mysql_thread.h:856
#5 0x00000000006413c0 in Checkable_rwlock::rdlock (this=0x0) at /home/laurynas/mysql-server/sql/rpl_gtid.h:347
#6 0x0000000000a546d9 in gtid_rollback (thd=0x7f578412bfc0) at /home/laurynas/mysql-server/sql/rpl_gtid_execution.cc:454
#7 0x0000000000651d91 in ha_rollback_trans (thd=0x7f578412bfc0, all=true) at /home/laurynas/mysql-server/sql/handler.cc:1716
#8 0x00000000008e95c1 in trans_rollback (thd=0x7f578412bfc0) at /home/laurynas/mysql-server/sql/transaction.cc:334
#9 0x00000000007babed in THD::cleanup (this=0x7f578412bfc0) at /home/laurynas/mysql-server/sql/sql_class.cc:1706
#10 0x00000000007bafba in THD::release_resources (this=0x7f578412bfc0) at /home/laurynas/mysql-server/sql/sql_class.cc:1792
#11 0x00007f57a61f2e0c in dena::dbcontext::term_thread (this=0x7f57840c51b0) at /home/laurynas/mysql-server/plugin/HandlerSocket-Plugin-for-MySQL/handlersocket/database.cpp:356
#12 0x00007f57a6200916 in dena::(anonymous namespace)::thr_init::~thr_init (this=0x7f577a7f3e80, __in_chrg=<optimized out>) at /home/laurynas/mysql-server/plugin/HandlerSocket-Plugin-for-MySQL/handlersocket/hstcpsvr_worker.cpp:314
#13 0x00007f57a6200ab1 in dena::hstcpsvr_worker::run (this=0x7f57840c50f0) at /home/laurynas/mysql-server/plugin/HandlerSocket-Plugin-for-MySQL/handlersocket/hstcpsvr_worker.cpp:324
#14 0x00007f57a620b495 in dena::worker_throbj::operator() (this=0x7f57840c50c0) at /home/laurynas/mysql-server/plugin/HandlerSocket-Plugin-for-MySQL/handlersocket/hstcpsvr.cpp:32
#15 0x00007f57a620ccf2 in dena::thread<dena::worker_throbj>::thread_main (arg=0x7f57840c50c0) at /home/laurynas/mysql-server/plugin/HandlerSocket-Plugin-for-MySQL/libhsclient/thread.hpp:71
#16 0x00007f57ab9b96fa in start_thread (arg=0x7f577a7f4700) at pthread_create.c:333
#17 0x00007f57aae4eb5d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

summary: - Intermittently stalled shutdown if it's issued immediately after
- HandlerSocket startup
+ Intermittently stalled or crashing shutdown if it's issued immediately
+ after HandlerSocket startup
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

The fix has caused bug 1666213

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

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.