|
|
10.3 670c9a3a
|
2019-12-05 4:45:32 0 [Note] /ten1/builds/10.3-670c9a3a-deb/bin/mysqld (initiated by: root[root] @ localhost [127.0.0.1]): Normal shutdown
|
2019-12-05 4:45:32 0 [Note] Event Scheduler: Purging the queue. 8 events
|
2019-12-05 4:45:32 0 [Note] InnoDB: FTS optimize thread exiting.
|
safe_mutex: Trying to lock uninitialized mutex at /home/elenst/src/10.3/sql/event_queue.cc, line 716
|
191205 4:45:32 [ERROR] mysqld got signal 6 ;
|
|
#3 <signal handler called>
|
#4 0x00007fe11c33f207 in raise () from /lib64/libc.so.6
|
#5 0x00007fe11c3408f8 in abort () from /lib64/libc.so.6
|
#6 0x0000559ff438d0ce in safe_mutex_lock (mp=0x559ff8639270, my_flags=0, file=0x559ff460b8c0 "/home/elenst/src/10.3/sql/event_queue.cc", line=716) at /home/elenst/src/10.3/mysys/thr_mutex.c:248
|
#7 0x0000559ff3caec66 in inline_mysql_mutex_lock (that=0x559ff8639270, src_file=0x559ff460b8c0 "/home/elenst/src/10.3/sql/event_queue.cc", src_line=716) at /home/elenst/src/10.3/include/mysql/psi/mysql_thread.h:710
|
#8 0x0000559ff3cb067f in Event_queue::lock_data (this=0x559ff8639270, func=0x559ff460c000 <Event_queue::drop_schema_events(THD*, st_mysql_const_lex_string const*)::__FUNCTION__> "drop_schema_events", line=389) at /home/elenst/src/10.3/sql/event_queue.cc:716
|
#9 0x0000559ff3cafa44 in Event_queue::drop_schema_events (this=0x559ff8639270, thd=0x7fe0a0000b90, schema=0x7fe0ec176de0) at /home/elenst/src/10.3/sql/event_queue.cc:389
|
#10 0x0000559ff38f4bbc in Events::drop_schema_events (thd=0x7fe0a0000b90, db=0x7fe0a0011568 "t") at /home/elenst/src/10.3/sql/events.cc:658
|
#11 0x0000559ff375847e in mysql_rm_db_internal (thd=0x7fe0a0000b90, db=0x7fe0a0005640, if_exists=true, silent=false) at /home/elenst/src/10.3/sql/sql_db.cc:929
|
#12 0x0000559ff3758af2 in mysql_rm_db (thd=0x7fe0a0000b90, db=0x7fe0a0005640, if_exists=true) at /home/elenst/src/10.3/sql/sql_db.cc:1055
|
#13 0x0000559ff37af751 in mysql_execute_command (thd=0x7fe0a0000b90) at /home/elenst/src/10.3/sql/sql_parse.cc:4981
|
#14 0x0000559ff37b8ccb in mysql_parse (thd=0x7fe0a0000b90, rawbuf=0x7fe0a0011488 "DROP DATABASE IF EXISTS t /* QNO 16092 CON_ID 13 */", length=51, parser_state=0x7fe0ec1785e0, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.3/sql/sql_parse.cc:7818
|
#15 0x0000559ff37a590d in dispatch_command (command=COM_QUERY, thd=0x7fe0a0000b90, packet=0x7fe0a0071b91 "DROP DATABASE IF EXISTS t /* QNO 16092 CON_ID 13 */ ", packet_length=52, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.3/sql/sql_parse.cc:1856
|
#16 0x0000559ff37a41a2 in do_command (thd=0x7fe0a0000b90) at /home/elenst/src/10.3/sql/sql_parse.cc:1402
|
#17 0x0000559ff391d9c3 in do_handle_one_connection (connect=0x559ff86390c0) at /home/elenst/src/10.3/sql/sql_connect.cc:1403
|
#18 0x0000559ff391d705 in handle_one_connection (arg=0x559ff86390c0) at /home/elenst/src/10.3/sql/sql_connect.cc:1308
|
#19 0x0000559ff3d138ef in pfs_spawn_thread (arg=0x559ff8648b70) at /home/elenst/src/10.3/storage/perfschema/pfs.cc:1862
|
#20 0x00007fe11d975dd5 in start_thread () from /lib64/libpthread.so.0
|
#21 0x00007fe11c406ead in clone () from /lib64/libc.so.6
|
|
10.3 61c0df94
|
2020-04-26 4:30:36 0 [Note] /ten1/builds/10.3-61c0df94-deb/bin/mysqld (initiated by: root[root] @ localhost [127.0.0.1]): Normal shutdown
|
2020-04-26 4:30:36 0 [Note] InnoDB: FTS optimize thread exiting.
|
2020-04-26 4:30:36 0 [Note] Event Scheduler: Purging the queue. 11 events
|
Got error 22 when trying to lock mutex LOCK_event_queue at /home/elenst/src/10.3/sql/event_queue.cc, line 716
|
200426 4:30:36 [ERROR] mysqld got signal 6 ;
|
|
#3 <signal handler called>
|
#4 0x00007f19a280f207 in raise () from /lib64/libc.so.6
|
#5 0x00007f19a28108f8 in abort () from /lib64/libc.so.6
|
#6 0x000055f94ad6b303 in safe_mutex_lock (mp=0x55f94f0e3870, my_flags=0, file=0x55f94b002080 "/home/elenst/src/10.3/sql/event_queue.cc", line=716) at /home/elenst/src/10.3/mysys/thr_mutex.c:300
|
#7 0x000055f94a68adf4 in inline_mysql_mutex_lock (that=0x55f94f0e3870, src_file=0x55f94b002080 "/home/elenst/src/10.3/sql/event_queue.cc", src_line=716) at /home/elenst/src/10.3/include/mysql/psi/mysql_thread.h:717
|
#8 0x000055f94a68c80d in Event_queue::lock_data (this=0x55f94f0e3870, func=0x55f94b0027c0 <Event_queue::drop_schema_events(THD*, st_mysql_const_lex_string const*)::__FUNCTION__> "drop_schema_events", line=389) at /home/elenst/src/10.3/sql/event_queue.cc:716
|
#9 0x000055f94a68bbd2 in Event_queue::drop_schema_events (this=0x55f94f0e3870, thd=0x7f1924000af0, schema=0x7f197c50de30) at /home/elenst/src/10.3/sql/event_queue.cc:389
|
#10 0x000055f94a2cefc6 in Events::drop_schema_events (thd=0x7f1924000af0, db=0x7f19240115c8 "g") at /home/elenst/src/10.3/sql/events.cc:658
|
#11 0x000055f94a132176 in mysql_rm_db_internal (thd=0x7f1924000af0, db=0x7f1924005598, if_exists=true, silent=false) at /home/elenst/src/10.3/sql/sql_db.cc:929
|
#12 0x000055f94a1327ea in mysql_rm_db (thd=0x7f1924000af0, db=0x7f1924005598, if_exists=true) at /home/elenst/src/10.3/sql/sql_db.cc:1055
|
#13 0x000055f94a1892e3 in mysql_execute_command (thd=0x7f1924000af0) at /home/elenst/src/10.3/sql/sql_parse.cc:4980
|
#14 0x000055f94a192835 in mysql_parse (thd=0x7f1924000af0, rawbuf=0x7f19240114e8 "DROP /* QNO 13747 CON_ID 14 */ DATABASE IF EXISTS g", length=51, parser_state=0x7f197c50f630, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.3/sql/sql_parse.cc:7817
|
#15 0x000055f94a17f4b6 in dispatch_command (command=COM_QUERY, thd=0x7f1924000af0, packet=0x7f19241171c1 "DROP /* QNO 13747 CON_ID 14 */ DATABASE IF EXISTS g", packet_length=51, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.3/sql/sql_parse.cc:1856
|
#16 0x000055f94a17dd48 in do_command (thd=0x7f1924000af0) at /home/elenst/src/10.3/sql/sql_parse.cc:1402
|
#17 0x000055f94a2f7df9 in do_handle_one_connection (connect=0x55f94f0adaa0) at /home/elenst/src/10.3/sql/sql_connect.cc:1403
|
#18 0x000055f94a2f7b3b in handle_one_connection (arg=0x55f94f0adaa0) at /home/elenst/src/10.3/sql/sql_connect.cc:1308
|
#19 0x00007f19a3e45dd5 in start_thread () from /lib64/libpthread.so.0
|
#20 0x00007f19a28d6ead in clone () from /lib64/libc.so.6
|
For the first failure, I have a test with a debug injection which makes it quite reproducible (although not 100%). Currently applicable to all of 10.1-10.5:
|
Injection
|
diff --git a/sql/event_queue.cc b/sql/event_queue.cc
|
index 6b3f5777df3..671f2a96220 100644
|
--- a/sql/event_queue.cc
|
+++ b/sql/event_queue.cc
|
@@ -713,6 +713,7 @@ Event_queue::lock_data(const char *func, uint line)
|
mutex_last_attempted_lock_in_func= func;
|
mutex_last_attempted_lock_at_line= line;
|
mutex_queue_data_attempting_lock= TRUE;
|
+ DBUG_EXECUTE_IF("sleep_event_queue",my_sleep(1000000););
|
mysql_mutex_lock(&LOCK_event_queue);
|
mutex_last_attempted_lock_in_func= "";
|
mutex_last_attempted_lock_at_line= 0;
|
|
Test
|
CREATE DATABASE db;
|
CREATE EVENT db.ev ON SCHEDULE EVERY 1 MINUTE DO SELECT 1;
|
--connect (con1,localhost,root,,)
|
SET DEBUG_DBUG='+d,sleep_event_queue';
|
--send
|
DROP DATABASE db;
|
|
--connection default
|
shutdown;
|
Or a variation with dropping only event, not the database (with a correspondingly different stack trace):
CREATE EVENT ev ON SCHEDULE EVERY 1 MINUTE DO SELECT 1;
|
--connect (con1,localhost,root,,)
|
SET DEBUG_DBUG='+d,sleep_event_queue';
|
--send
|
DROP EVENT ev;
|
|
--connection default
|
shutdown;
|
The second failure, error 22, actually happens more often in the concurrent tests, but I don't have an injection for it. Both happen on server shutdown are otherwise very similar, I hope they will be solved together. All threads' stack trace for the second failure is attached as error22_all_threads .
|
error22_all_threads