Note that there is a significant SHUTDOWN command in the testcase, so standard run methods (like MTR/CLI) may not work
MTR is perfectly capable of handling the SHUTDOWN command if it's indeed important, there is even a dedicated test for it, check it out.
It is more likely however that the important part is not the SHUTDOWN command as such, but the server restart in general, which is a part of the basic functionality of the MTR framework.
|
|
Roel, what restarts the server in your tests? Without a restart a shutdown would've been the last executed command
|
|
serg Had to step back to the script for a bit and review. The script starts 2 mysqld servers, then (if issue was not observed) 10... 20, 30, 40, 50, 100 servers simultaneously, and executes 200 client threads, simultaneously (as Bash background processes using the CLI) against each mysqld. Then, after this is does a waiting (35 sec timeout) mysqladmin shutdown. After this, it checks all started mysqld instances to see if a given text (like 'signal') was found, or if a core dump was written. The issue reproduced readily in the past with about 10 myqld instances started, each with 200 client threads, non-random, sequentially executing the SQL above in each of those 200 client threads. Now, about 30 to 50 mysqld instances (again each with their own, sequential, 200 client threads) are needed to generate a core, and in this case I got a different crash:
|
10.6.0 a3e3225cd3b816d47621e749e21a71b6a864a96a (Debug)
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 inline_mysql_mutex_lock (src_line=733, src_file=0x56435815e938 "/test/10.6_dbg/sql/event_scheduler.cc", that=0x0)
|
at /test/10.6_dbg/include/mysql/psi/mysql_thread.h:745
|
[Current thread is 1 (Thread 0x153154076700 (LWP 291412))]
|
(gdb) bt
|
#0 inline_mysql_mutex_lock (src_line=733, src_file=0x56435815e938 "/test/10.6_dbg/sql/event_scheduler.cc", that=0x0)
|
at /test/10.6_dbg/include/mysql/psi/mysql_thread.h:745
|
#1 Event_scheduler::lock_data (this=this@entry=0x0, func=func@entry=0x56435812bd27 "start", line=line@entry=399)
|
at /test/10.6_dbg/sql/event_scheduler.cc:733
|
#2 0x00005643577eede9 in Event_scheduler::start (this=0x0, err_no=err_no@entry=0x153154074d7c)
|
at /test/10.6_dbg/sql/event_scheduler.cc:399
|
#3 0x0000564357438941 in Events::start (err_no=err_no@entry=0x153154074d7c) at /test/10.6_dbg/sql/events.cc:1128
|
#4 0x0000564357477eaf in event_scheduler_update (self=<optimized out>, thd=<optimized out>, type=<optimized out>)
|
at /test/10.6_dbg/sql/sys_vars.cc:1125
|
#5 0x00005643572094e0 in sys_var::update (this=0x5643588ffdc0 <Sys_event_scheduler>, thd=0x153104000db8,
|
var=0x153104013d08) at /test/10.6_dbg/sql/set_var.cc:207
|
#6 0x00005643572099f7 in set_var::update (this=<optimized out>, thd=<optimized out>)
|
at /test/10.6_dbg/sql/set_var.cc:859
|
#7 0x000056435720ad42 in sql_set_variables (thd=thd@entry=0x153104000db8, var_list=var_list@entry=0x153104005ec0,
|
free=free@entry=true) at /test/10.6_dbg/sql/set_var.cc:746
|
#8 0x000056435730984c in mysql_execute_command (thd=thd@entry=0x153104000db8) at /test/10.6_dbg/sql/sql_parse.cc:5030
|
#9 0x00005643572f2a06 in mysql_parse (thd=thd@entry=0x153104000db8, rawbuf=<optimized out>, length=<optimized out>,
|
parser_state=parser_state@entry=0x153154075410) at /test/10.6_dbg/sql/sql_parse.cc:8017
|
#10 0x00005643573017df in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x153104000db8,
|
packet=packet@entry=0x15310400b369 "SET GLOBAL event_scheduler=1", packet_length=packet_length@entry=28,
|
blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1331
|
#11 0x0000564357304bd5 in do_command (thd=0x153104000db8, blocking=blocking@entry=true)
|
at /test/10.6_dbg/sql/sql_parse.cc:1406
|
#12 0x000056435745e77c in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56435a908088,
|
put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
|
#13 0x000056435745ed81 in handle_one_connection (arg=arg@entry=0x56435a908088)
|
at /test/10.6_dbg/sql/sql_connect.cc:1312
|
#14 0x000056435790ca03 in pfs_spawn_thread (arg=0x56435aa31fd8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
|
#15 0x0000153160f82609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#16 0x0000153160b71293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
Note that the threads is executing "SET GLOBAL event_scheduler=1;", and as the SQL is sequential, it is thus possible for a command to be executed even if SHUTDOWN is already in process (either by the SHUTDOWN command itself or my the mysqladmin shutdown).
|
|
an easy way to repeat it is to run in mysql cli
MariaDB> shutdown;set global event_scheduler=1;
|
this crashes in about 10 attempts
|
|
Great. Thank you serg for testing on your end.
|
|
I had another stack today with this similar testcase:
SHUTDOWN;
|
SET GLOBAL event_scheduler=1;
|
SELECT SLEEP (3);
|
|
10.7.0 52505bf20de0ce77a5c0b0a74af021051987bb0d (Debug)
|
Core was generated by `/test/MD160821-mariadb-10.7.0-linux-x86_64-dbg/bin/mysqld --no-defaults --max_a'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 0x000055e328c281f4 in my_hash_first (hash=0x55e32a77b058,
|
key=key@entry=0x55e32971d858 <LOCK_thread_id+120> "7",
|
length=length@entry=0, current_record=current_record@entry=0x14b9ab4fdbcc)
|
at /test/10.7_dbg/mysys/hash.c:262
|
[Current thread is 1 (Thread 0x14b9ab4ff700 (LWP 1545540))]
|
(gdb) bt
|
#0 0x000055e328c281f4 in my_hash_first (hash=0x55e32a77b058, key=key@entry=0x55e32971d858 <LOCK_thread_id+120> "7", length=length@entry=0, current_record=current_record@entry=0x14b9ab4fdbcc) at /test/10.7_dbg/mysys/hash.c:262
|
#1 0x000055e328c28269 in my_hash_search (hash=<optimized out>, key=key@entry=0x55e32971d858 <LOCK_thread_id+120> "7", length=length@entry=0) at /test/10.7_dbg/mysys/hash.c:235
|
#2 0x000055e328c4fbcd in safe_mutex_lock (mp=mp@entry=0x55e32971d7e0 <LOCK_thread_id>, my_flags=my_flags@entry=0, file=file@entry=0x55e328da8448 "/test/10.7_dbg/sql/mysqld.cc", line=line@entry=9707) at /test/10.7_dbg/mysys/thr_mutex.c:335
|
#3 0x000055e328010c2f in inline_mysql_mutex_lock (src_line=9707, src_file=0x55e328da8448 "/test/10.7_dbg/sql/mysqld.cc", that=0x55e32971d7e0 <LOCK_thread_id>) at /test/10.7_dbg/include/mysql/psi/mysql_thread.h:750
|
#4 next_thread_id () at /test/10.7_dbg/sql/mysqld.cc:9707
|
#5 0x000055e328629ef4 in Event_scheduler::start (this=0x55e32a75d750, err_no=err_no@entry=0x14b9ab4fdd4c) at /test/10.7_dbg/sql/event_scheduler.cc:404
|
#6 0x000055e3282a7eb9 in Events::start (err_no=err_no@entry=0x14b9ab4fdd4c) at /test/10.7_dbg/sql/events.cc:1133
|
#7 0x000055e3282e8889 in event_scheduler_update (self=<optimized out>, thd=<optimized out>, type=<optimized out>) at /test/10.7_dbg/sql/sys_vars.cc:1148
|
#8 0x000055e328056bf4 in sys_var::update (this=0x55e3297486e0 <Sys_event_scheduler>, thd=0x14b964000db8, var=0x14b96509ac20) at /test/10.7_dbg/sql/set_var.cc:207
|
#9 0x000055e328057101 in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.7_dbg/sql/set_var.cc:863
|
#10 0x000055e328058447 in sql_set_variables (thd=thd@entry=0x14b964000db8, var_list=var_list@entry=0x14b964006028, free=free@entry=true) at /test/10.7_dbg/sql/set_var.cc:745
|
#11 0x000055e32815c505 in mysql_execute_command (thd=thd@entry=0x14b964000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.7_dbg/sql/sql_parse.cc:5036
|
#12 0x000055e328145ac3 in mysql_parse (thd=thd@entry=0x14b964000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14b9ab4fe400) at /test/10.7_dbg/sql/sql_parse.cc:8030
|
#13 0x000055e3281546c8 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14b964000db8, packet=packet@entry=0x14b964afe349 "SET @@global.event_scheduler = 1;", packet_length=packet_length@entry=33, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_class.h:1357
|
#14 0x000055e328157ae9 in do_command (thd=0x14b964000db8, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_parse.cc:1404
|
#15 0x000055e3282cddd6 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e32a73a868, put_in_cache=put_in_cache@entry=true) at /test/10.7_dbg/sql/sql_connect.cc:1418
|
#16 0x000055e3282ce3db in handle_one_connection (arg=arg@entry=0x55e32a73a868) at /test/10.7_dbg/sql/sql_connect.cc:1312
|
#17 0x000055e328736ce4 in pfs_spawn_thread (arg=0x55e32a63abc8) at /test/10.7_dbg/storage/perfschema/pfs.cc:2201
|
#18 0x000014b9ce8f1609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#19 0x000014b9ce4df293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
Observed on 10.11, with testcase above, this stack:
|
10.11.0 bc563f1a4b0b38de3b41fd0f0d3d8b7f1aacbd8b (Debug)
|
Core was generated by `/test/MD190822-mariadb-10.11.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 __GI___pthread_mutex_lock (mutex=mutex@entry=0x0)
|
at ../nptl/pthread_mutex_lock.c:67
|
[Current thread is 1 (Thread 0x14a53c2ad700 (LWP 3975670))]
|
(gdb) bt
|
#0 __GI___pthread_mutex_lock (mutex=mutex@entry=0x0) at ../nptl/pthread_mutex_lock.c:67
|
#1 0x000055921c9aea7c in safe_mutex_lock (mp=mp@entry=0x0, my_flags=my_flags@entry=0, file=file@entry=0x55921cd348d0 "/test/10.11_dbg/sql/event_scheduler.cc", line=line@entry=733) at /test/10.11_dbg/mysys/thr_mutex.c:238
|
#2 0x000055921c4467fa in inline_mysql_mutex_lock (src_line=733, src_file=0x55921cd348d0 "/test/10.11_dbg/sql/event_scheduler.cc", that=0x0) at /test/10.11_dbg/include/mysql/psi/mysql_thread.h:750
|
#3 Event_scheduler::lock_data (this=this@entry=0x0, func=func@entry=0x55921cd0867d "start", line=line@entry=399) at /test/10.11_dbg/sql/event_scheduler.cc:733
|
#4 0x000055921c446922 in Event_scheduler::start (this=0x0, err_no=err_no@entry=0x14a53c2abcdc) at /test/10.11_dbg/sql/event_scheduler.cc:399
|
#5 0x000055921c0c3347 in Events::start (err_no=err_no@entry=0x14a53c2abcdc) at /test/10.11_dbg/sql/events.cc:1135
|
#6 0x000055921c0ff263 in event_scheduler_update (self=<optimized out>, thd=0x14a500000db8, type=<optimized out>) at /test/10.11_dbg/sql/sys_vars.cc:1163
|
#7 0x000055921be96144 in sys_var::update (this=0x55921d572580 <Sys_event_scheduler>, thd=0x14a500000db8, var=0x14a500013d78) at /test/10.11_dbg/sql/set_var.cc:207
|
#8 0x000055921be96651 in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.11_dbg/sql/set_var.cc:863
|
#9 0x000055921be978ef in sql_set_variables (thd=thd@entry=0x14a500000db8, var_list=var_list@entry=0x14a500005f08, free=free@entry=true) at /test/10.11_dbg/sql/set_var.cc:745
|
#10 0x000055921bf8983c in mysql_execute_command (thd=thd@entry=0x14a500000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.11_dbg/sql/sql_parse.cc:5034
|
#11 0x000055921bf74882 in mysql_parse (thd=thd@entry=0x14a500000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14a53c2ac330) at /test/10.11_dbg/sql/sql_parse.cc:8035
|
#12 0x000055921bf81e6a in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14a500000db8, packet=packet@entry=0x14a50000b6e9 "set global event_scheduler=1", packet_length=packet_length@entry=28, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_class.h:1339
|
#13 0x000055921bf84574 in do_command (thd=0x14a500000db8, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
|
#14 0x000055921c0e61da in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55921f6675e8, put_in_cache=put_in_cache@entry=true) at /test/10.11_dbg/sql/sql_connect.cc:1418
|
#15 0x000055921c0e66e3 in handle_one_connection (arg=0x55921f6675e8) at /test/10.11_dbg/sql/sql_connect.cc:1312
|
#16 0x000014a55551d609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#17 0x000014a555109133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
Same stack observed on 10.10, same testcase.
|
|
10.8 crashes in my_hash:
|
10.8.5 445234942abfaeff3cc8f791f7757a2f9edbb246 (Debug)
|
Core was generated by `/test/MD200822-mariadb-10.8.5-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 0x0000564aed440c76 in my_hash_first (hash=0x564af05a6c38,
|
key=key@entry=0x564aedefa658 <LOCK_thread_id+120> "\005\001",
|
length=length@entry=8, current_record=current_record@entry=0x152ada41abdc)
|
at /test/10.8_dbg/mysys/hash.c:262
|
[Current thread is 1 (Thread 0x152ada41c700 (LWP 1122564))]
|
(gdb) bt
|
#0 0x0000564aed440c76 in my_hash_first (hash=0x564af05a6c38, key=key@entry=0x564aedefa658 <LOCK_thread_id+120> "\005\001", length=length@entry=8, current_record=current_record@entry=0x152ada41abdc) at /test/10.8_dbg/mysys/hash.c:262
|
#1 0x0000564aed440ceb in my_hash_search (hash=<optimized out>, key=key@entry=0x564aedefa658 <LOCK_thread_id+120> "\005\001", length=length@entry=8) at /test/10.8_dbg/mysys/hash.c:235
|
#2 0x0000564aed462b0b in safe_mutex_lock (mp=mp@entry=0x564aedefa5e0 <LOCK_thread_id>, my_flags=my_flags@entry=0, file=file@entry=0x564aed5e5480 "/test/10.8_dbg/sql/mysqld.cc", line=line@entry=9811) at /test/10.8_dbg/mysys/thr_mutex.c:335
|
#3 0x0000564aec914198 in inline_mysql_mutex_lock (src_line=9811, src_file=0x564aed5e5480 "/test/10.8_dbg/sql/mysqld.cc", that=0x564aedefa5e0 <LOCK_thread_id>) at /test/10.8_dbg/include/mysql/psi/mysql_thread.h:750
|
#4 next_thread_id () at /test/10.8_dbg/sql/mysqld.cc:9811
|
#5 0x0000564aecefd00c in Event_scheduler::start (this=0x564af0588e50, err_no=err_no@entry=0x152ada41ad1c) at /test/10.8_dbg/sql/event_scheduler.cc:404
|
#6 0x0000564aecb8278d in Events::start (err_no=err_no@entry=0x152ada41ad1c) at /test/10.8_dbg/sql/events.cc:1134
|
#7 0x0000564aecbbd07b in event_scheduler_update (self=<optimized out>, thd=0x152a98000db8, type=<optimized out>) at /test/10.8_dbg/sql/sys_vars.cc:1161
|
#8 0x0000564aec95901a in sys_var::update (this=0x564aedf257c0 <Sys_event_scheduler>, thd=0x152a98000db8, var=0x152a98013d18) at /test/10.8_dbg/sql/set_var.cc:207
|
#9 0x0000564aec959527 in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.8_dbg/sql/set_var.cc:863
|
#10 0x0000564aec95a7c5 in sql_set_variables (thd=thd@entry=0x152a98000db8, var_list=var_list@entry=0x152a98005ee0, free=free@entry=true) at /test/10.8_dbg/sql/set_var.cc:745
|
#11 0x0000564aeca4b4be in mysql_execute_command (thd=thd@entry=0x152a98000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.8_dbg/sql/sql_parse.cc:5034
|
#12 0x0000564aeca3659b in mysql_parse (thd=thd@entry=0x152a98000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x152ada41b330) at /test/10.8_dbg/sql/sql_parse.cc:8028
|
#13 0x0000564aeca43c43 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x152a98000db8, packet=packet@entry=0x152a9800b689 "set global event_scheduler=1", packet_length=packet_length@entry=28, blocking=blocking@entry=true) at /test/10.8_dbg/sql/sql_class.h:1362
|
#14 0x0000564aeca46350 in do_command (thd=0x152a98000db8, blocking=blocking@entry=true) at /test/10.8_dbg/sql/sql_parse.cc:1407
|
#15 0x0000564aecba40c6 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x564af058f8a8, put_in_cache=put_in_cache@entry=true) at /test/10.8_dbg/sql/sql_connect.cc:1418
|
#16 0x0000564aecba45cf in handle_one_connection (arg=0x564af058f8a8) at /test/10.8_dbg/sql/sql_connect.cc:1312
|
#17 0x0000152af348b609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#18 0x0000152af3077133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
Also affect optimized builds. 10.11 Optimized:
|
10.11.0 bc563f1a4b0b38de3b41fd0f0d3d8b7f1aacbd8b (Optimized)
|
Core was generated by `/test/MD190822-mariadb-10.11.0-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 __GI___pthread_mutex_lock (mutex=mutex@entry=0x0)
|
at ../nptl/pthread_mutex_lock.c:67
|
[Current thread is 1 (Thread 0x146fa40f3700 (LWP 1311844))]
|
(gdb) bt
|
#0 __GI___pthread_mutex_lock (mutex=mutex@entry=0x0) at ../nptl/pthread_mutex_lock.c:67
|
#1 0x000055ac3e479e8f in inline_mysql_mutex_lock (that=0x0) at /test/10.11_opt/include/mysql/psi/mysql_thread.h:752
|
#2 Event_scheduler::lock_data (this=this@entry=0x0, func=func@entry=0x55ac3e96236b "start", line=line@entry=399) at /test/10.11_opt/sql/event_scheduler.cc:733
|
#3 0x000055ac3e479f4a in Event_scheduler::start (this=0x0, err_no=err_no@entry=0x146fa40f1e2c) at /test/10.11_opt/sql/event_scheduler.cc:399
|
#4 0x000055ac3e1ca706 in Events::start (err_no=err_no@entry=0x146fa40f1e2c) at /test/10.11_opt/sql/events.cc:1135
|
#5 0x000055ac3e1f5459 in event_scheduler_update (self=<optimized out>, thd=0x146f6c000c58, type=<optimized out>) at /test/10.11_opt/sql/sys_vars.cc:1158
|
#6 0x000055ac3e0037e2 in sys_var::update (this=0x55ac3f2716a0 <Sys_event_scheduler>, thd=0x146f6c000c58, var=0x146f6c010858) at /test/10.11_opt/include/mysql/psi/mysql_thread.h:795
|
#7 0x000055ac3e003c4b in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.11_opt/sql/set_var.cc:863
|
#8 0x000055ac3e004d19 in sql_set_variables (thd=thd@entry=0x146f6c000c58, var_list=var_list@entry=0x146f6c005be8, free=free@entry=true) at /test/10.11_opt/sql/set_var.cc:745
|
#9 0x000055ac3e0cee64 in mysql_execute_command (thd=0x146f6c000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.11_opt/sql/sql_parse.cc:5034
|
#10 0x000055ac3e0bd7b5 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x146f6c000c58) at /test/10.11_opt/sql/sql_parse.cc:8035
|
#11 mysql_parse (thd=0x146f6c000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.11_opt/sql/sql_parse.cc:7957
|
#12 0x000055ac3e0c92ca in dispatch_command (command=COM_QUERY, thd=0x146f6c000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.11_opt/sql/sql_class.h:1339
|
#13 0x000055ac3e0cb1f2 in do_command (thd=0x146f6c000c58, blocking=blocking@entry=true) at /test/10.11_opt/sql/sql_parse.cc:1407
|
#14 0x000055ac3e1e346f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55ac40936f58, put_in_cache=put_in_cache@entry=true) at /test/10.11_opt/sql/sql_connect.cc:1418
|
#15 0x000055ac3e1e374d in handle_one_connection (arg=0x55ac40936f58) at /test/10.11_opt/sql/sql_connect.cc:1312
|
#16 0x0000146fd0791609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#17 0x0000146fd037d133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
10.6 crashing in my_hash on recent build:
|
10.6.10 75c416d3627650a5b43c70a8150292990206e3e0 (Debug)
|
Core was generated by `/test/MD200822-mariadb-10.6.10-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 0x000056425c4dce21 in my_hash_key (first=1 '\001', length=0x153e517c7b08,
|
record=0x0, hash=0x56425de438f8) at /test/10.6_dbg/mysys/hash.c:196
|
[Current thread is 1 (Thread 0x153e517c9700 (LWP 2466589))]
|
(gdb) bt
|
#0 0x000056425c4dce21 in my_hash_key (first=1 '\001', length=0x153e517c7b08, record=0x0, hash=0x56425de438f8) at /test/10.6_dbg/mysys/hash.c:196
|
#1 hashcmp (hash=hash@entry=0x56425de438f8, pos=pos@entry=0x564b56dd3368, key=key@entry=0x56425cf6e978 <LOCK_thread_id+120> "\262", length=length@entry=0) at /test/10.6_dbg/mysys/hash.c:371
|
#2 0x000056425c4dd133 in my_hash_first_from_hash_value (hash=hash@entry=0x56425de438f8, hash_value=<optimized out>, key=key@entry=0x56425cf6e978 <LOCK_thread_id+120> "\262", length=length@entry=0, current_record=current_record@entry=0x153e517c7bdc) at /test/10.6_dbg/mysys/hash.c:288
|
#3 0x000056425c4dd1d4 in my_hash_first (hash=0x56425de438f8, key=key@entry=0x56425cf6e978 <LOCK_thread_id+120> "\262", length=length@entry=0, current_record=current_record@entry=0x153e517c7bdc) at /test/10.6_dbg/mysys/hash.c:262
|
#4 0x000056425c4dd234 in my_hash_search (hash=<optimized out>, key=key@entry=0x56425cf6e978 <LOCK_thread_id+120> "\262", length=length@entry=0) at /test/10.6_dbg/mysys/hash.c:235
|
#5 0x000056425c4ff0cb in safe_mutex_lock (mp=mp@entry=0x56425cf6e900 <LOCK_thread_id>, my_flags=my_flags@entry=0, file=file@entry=0x56425c66b464 "/test/10.6_dbg/sql/mysqld.cc", line=line@entry=9754) at /test/10.6_dbg/mysys/thr_mutex.c:335
|
#6 0x000056425b9d5e15 in inline_mysql_mutex_lock (src_line=9754, src_file=0x56425c66b464 "/test/10.6_dbg/sql/mysqld.cc", that=0x56425cf6e900 <LOCK_thread_id>) at /test/10.6_dbg/include/mysql/psi/mysql_thread.h:750
|
#7 next_thread_id () at /test/10.6_dbg/sql/mysqld.cc:9754
|
#8 0x000056425bf970fc in Event_scheduler::start (this=0x56425de178b0, err_no=err_no@entry=0x153e517c7d1c) at /test/10.6_dbg/sql/event_scheduler.cc:404
|
#9 0x000056425bbf9a0b in Events::start (err_no=err_no@entry=0x153e517c7d1c) at /test/10.6_dbg/sql/events.cc:1134
|
#10 0x000056425bc33e3b in event_scheduler_update (self=<optimized out>, thd=0x153e18000db8, type=<optimized out>) at /test/10.6_dbg/sql/sys_vars.cc:1144
|
#11 0x000056425b9eabe0 in sys_var::update (this=0x56425cf99720 <Sys_event_scheduler>, thd=0x153e18000db8, var=0x153e18013ee8) at /test/10.6_dbg/sql/set_var.cc:207
|
#12 0x000056425b9eb0ed in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.6_dbg/sql/set_var.cc:863
|
#13 0x000056425b9ec38b in sql_set_variables (thd=thd@entry=0x153e18000db8, var_list=var_list@entry=0x153e18005e28, free=free@entry=true) at /test/10.6_dbg/sql/set_var.cc:745
|
#14 0x000056425bad6b8e in mysql_execute_command (thd=thd@entry=0x153e18000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.6_dbg/sql/sql_parse.cc:5036
|
#15 0x000056425bac1c42 in mysql_parse (thd=thd@entry=0x153e18000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x153e517c8330) at /test/10.6_dbg/sql/sql_parse.cc:8030
|
#16 0x000056425bacf315 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x153e18000db8, packet=packet@entry=0x153e1800b569 "set global event_scheduler=1", packet_length=packet_length@entry=28, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1358
|
#17 0x000056425bad1a22 in do_command (thd=0x153e18000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1409
|
#18 0x000056425bc1b12a in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56425de106c8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1418
|
#19 0x000056425bc1b633 in handle_one_connection (arg=0x56425de106c8) at /test/10.6_dbg/sql/sql_connect.cc:1312
|
#20 0x0000153e6a45f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#21 0x0000153e6a04b133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
10.9 crashes in another location: my_hash_iterate
|
10.9.2 8cb75b9863a7043ebf2545158b3d2e634bca1831 (Debug)
|
Core was generated by `/test/MD200822-mariadb-10.9.2-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 0x0000560c22d8e9ae in my_hash_iterate (hash=0x560c257f9e38,
|
action=action@entry=0x560c22daf818 <add_used_to_locked_mutex>,
|
argument=argument@entry=0x147b3c019fe8) at /test/10.9_dbg/mysys/hash.c:808
|
[Current thread is 1 (Thread 0x147b8541a700 (LWP 2221261))]
|
(gdb) bt
|
#0 0x0000560c22d8e9ae in my_hash_iterate (hash=0x560c257f9e38, action=action@entry=0x560c22daf818 <add_used_to_locked_mutex>, argument=argument@entry=0x147b3c019fe8) at /test/10.9_dbg/mysys/hash.c:808
|
#1 0x0000560c22db005e in safe_mutex_lock (mp=mp@entry=0x560c2384d6e0 <LOCK_thread_id>, my_flags=my_flags@entry=0, file=file@entry=0x560c22f33480 "/test/10.9_dbg/sql/mysqld.cc", line=line@entry=9822) at /test/10.9_dbg/mysys/thr_mutex.c:378
|
#2 0x0000560c22256198 in inline_mysql_mutex_lock (src_line=9822, src_file=0x560c22f33480 "/test/10.9_dbg/sql/mysqld.cc", that=0x560c2384d6e0 <LOCK_thread_id>) at /test/10.9_dbg/include/mysql/psi/mysql_thread.h:750
|
#3 next_thread_id () at /test/10.9_dbg/sql/mysqld.cc:9822
|
#4 0x0000560c22848b0a in Event_scheduler::start (this=0x560c257dba70, err_no=err_no@entry=0x147b85418cdc) at /test/10.9_dbg/sql/event_scheduler.cc:404
|
#5 0x0000560c224c66e7 in Events::start (err_no=err_no@entry=0x147b85418cdc) at /test/10.9_dbg/sql/events.cc:1134
|
#6 0x0000560c2250259f in event_scheduler_update (self=<optimized out>, thd=0x147b3c000db8, type=<optimized out>) at /test/10.9_dbg/sql/sys_vars.cc:1163
|
#7 0x0000560c2229b04a in sys_var::update (this=0x560c23878f20 <Sys_event_scheduler>, thd=0x147b3c000db8, var=0x147b3c013d58) at /test/10.9_dbg/sql/set_var.cc:207
|
#8 0x0000560c2229b557 in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.9_dbg/sql/set_var.cc:863
|
#9 0x0000560c2229c7f5 in sql_set_variables (thd=thd@entry=0x147b3c000db8, var_list=var_list@entry=0x147b3c005ef0, free=free@entry=true) at /test/10.9_dbg/sql/set_var.cc:745
|
#10 0x0000560c2238e532 in mysql_execute_command (thd=thd@entry=0x147b3c000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.9_dbg/sql/sql_parse.cc:5034
|
#11 0x0000560c22379586 in mysql_parse (thd=thd@entry=0x147b3c000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x147b85419330) at /test/10.9_dbg/sql/sql_parse.cc:8037
|
#12 0x0000560c22386b6e in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x147b3c000db8, packet=packet@entry=0x147b3c00b6c9 "set global event_scheduler=1", packet_length=packet_length@entry=28, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_class.h:1364
|
#13 0x0000560c22389278 in do_command (thd=0x147b3c000db8, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_parse.cc:1407
|
#14 0x0000560c224e9562 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x560c257d4828, put_in_cache=put_in_cache@entry=true) at /test/10.9_dbg/sql/sql_connect.cc:1418
|
#15 0x0000560c224e9a6b in handle_one_connection (arg=0x560c257d4828) at /test/10.9_dbg/sql/sql_connect.cc:1312
|
#16 0x0000147b9e894609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#17 0x0000147b9e480133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
10.4
|
10.4.27 3101751f505f39d2ccecd03a916ecdbf2f380740 (Debug)
|
Core was generated by `/test/MD200822-mariadb-10.4.27-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 __GI___pthread_mutex_lock (mutex=mutex@entry=0x0)
|
at ../nptl/pthread_mutex_lock.c:67
|
[Current thread is 1 (Thread 0x14639d36c700 (LWP 1784906))]
|
(gdb) bt
|
#0 __GI___pthread_mutex_lock (mutex=mutex@entry=0x0) at ../nptl/pthread_mutex_lock.c:67
|
#1 0x0000560c81ff888a in safe_mutex_lock (mp=mp@entry=0x0, my_flags=my_flags@entry=0, file=file@entry=0x560c82316a40 "/test/10.4_dbg/sql/event_scheduler.cc", line=line@entry=717) at /test/10.4_dbg/mysys/thr_mutex.c:241
|
#2 0x0000560c819e5278 in inline_mysql_mutex_lock (src_line=717, src_file=0x560c82316a40 "/test/10.4_dbg/sql/event_scheduler.cc", that=0x0) at /test/10.4_dbg/include/mysql/psi/mysql_thread.h:717
|
#3 Event_scheduler::lock_data (this=this@entry=0x0, func=func@entry=0x560c822e97e8 "start", line=line@entry=386) at /test/10.4_dbg/sql/event_scheduler.cc:717
|
#4 0x0000560c819e53a0 in Event_scheduler::start (this=0x0, err_no=err_no@entry=0x14639d369a5c) at /test/10.4_dbg/sql/event_scheduler.cc:386
|
#5 0x0000560c816789a9 in Events::start (err_no=err_no@entry=0x14639d369a5c) at /test/10.4_dbg/sql/events.cc:1123
|
#6 0x0000560c816aaf7b in event_scheduler_update (self=<optimized out>, thd=0x146350000d90, type=<optimized out>) at /test/10.4_dbg/sql/sys_vars.cc:1072
|
#7 0x0000560c8148d01e in sys_var::update (this=0x560c82a277c0 <Sys_event_scheduler>, thd=0x146350000d90, var=0x1463500131f8) at /test/10.4_dbg/sql/set_var.cc:208
|
#8 0x0000560c8148d535 in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.4_dbg/sql/set_var.cc:837
|
#9 0x0000560c8148e738 in sql_set_variables (thd=thd@entry=0x146350000d90, var_list=var_list@entry=0x146350005a68, free=free@entry=true) at /test/10.4_dbg/sql/set_var.cc:740
|
#10 0x0000560c81568f7f in mysql_execute_command (thd=thd@entry=0x146350000d90) at /test/10.4_dbg/sql/sql_parse.cc:5022
|
#11 0x0000560c8156ef3d in mysql_parse (thd=thd@entry=0x146350000d90, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14639d36b3f0, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_parse.cc:7996
|
#12 0x0000560c81571a63 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x146350000d90, packet=packet@entry=0x14635001a1d1 "set global event_scheduler=1", packet_length=packet_length@entry=28, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.4_dbg/sql/sql_class.h:1201
|
#13 0x0000560c81574524 in do_command (thd=0x146350000d90) at /test/10.4_dbg/sql/sql_parse.cc:1378
|
#14 0x0000560c8169586b in do_handle_one_connection (connect=<optimized out>) at /test/10.4_dbg/sql/sql_connect.cc:1420
|
#15 0x0000560c8169592b in handle_one_connection (arg=<optimized out>) at /test/10.4_dbg/sql/sql_connect.cc:1316
|
#16 0x00001463b8358609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#17 0x00001463b7f44133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
With this sporadic but simple testcase:
SET GLOBAL event_scheduler=TRUE;
|
SHUTDOWN;
|
SET GLOBAL event_scheduler=TRUE;
|
SET GLOBAL event_scheduler=TRUE;
|
SET GLOBAL event_scheduler=TRUE;
|
This error can be observed after a number of runs against the CLI (not sure how to translate this testcase to MTR):
|
11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)
|
Got error 22 when trying to lock mutex LOCK_scheduler_state at /test/11.0_dbg/sql/event_scheduler.cc, line 733
|
And stack smashing is present:
|
11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)
|
Core was generated by `/test/MD090123-mariadb-11.0.1-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
|
Program terminated with signal SIGABRT, Aborted.
|
#0 0x0000151ff12b4a7c in ?? ()
|
[Current thread is 1 (LWP 3757915)]
|
(gdb) bt
|
#0 0x0000151ff12b4a7c in ?? ()
|
#1 0x000055aa7e119408 in ?? ()
|
#2 0x0000151ff129fa09 in ?? ()
|
#3 0x00000000fbad8001 in ?? ()
|
#4 0x0000151fd857db30 in ?? ()
|
#5 0x0000151fd857db30 in ?? ()
|
#6 0x0000151fd857db30 in ?? ()
|
#7 0x0000151fd857db30 in ?? ()
|
#8 0x0000151fd857db34 in ?? ()
|
#9 0x0000151fd857db93 in ?? ()
|
#10 0x0000151fd857db30 in ?? ()
|
#11 0x0000151fd857db93 in ?? ()
|
#12 0x0000000000000000 in ?? ()
|
With the same testcase (again looping it - about 5-10 times), we can see this stack at times:
|
11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)
|
Core was generated by `/test/MD090123-mariadb-11.0.1-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
|
Program terminated with signal SIGABRT, Aborted.
|
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=22394356479552)
|
at ./nptl/pthread_kill.c:44
|
[Current thread is 1 (Thread 0x145e17a9b640 (LWP 89133))]
|
(gdb) bt
|
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=22394356479552) at ./nptl/pthread_kill.c:44
|
#1 __pthread_kill_internal (signo=6, threadid=22394356479552) at ./nptl/pthread_kill.c:78
|
#2 __GI___pthread_kill (threadid=22394356479552, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
|
#3 0x0000145e4ffec476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
|
#4 0x0000145e4ffd27f3 in __GI_abort () at ./stdlib/abort.c:79
|
#5 0x0000556ed332d9a9 in safe_mutex_lock (mp=0x556ed60e9300, my_flags=<optimized out>, file=0x556ed35d6008 "/test/11.0_dbg/sql/event_scheduler.cc", line=733) at /test/11.0_dbg/mysys/thr_mutex.c:297
|
#6 0x0000556ed2e47198 in inline_mysql_mutex_lock (src_line=733, src_file=0x556ed35d6008 "/test/11.0_dbg/sql/event_scheduler.cc", that=0x556ed60e9300) at /test/11.0_dbg/include/mysql/psi/mysql_thread.h:750
|
#7 Event_scheduler::lock_data (this=this@entry=0x556ed60e9300, func=func@entry=0x556ed35d5f20 "is_running", line=line@entry=609) at /test/11.0_dbg/sql/event_scheduler.cc:733
|
#8 0x0000556ed2e47210 in Event_scheduler::is_running (this=this@entry=0x556ed60e9300) at /test/11.0_dbg/sql/event_scheduler.cc:609
|
#9 0x0000556ed2e474f9 in Event_scheduler::run (this=this@entry=0x556ed60e9300, thd=0x145e00027638) at /test/11.0_dbg/sql/event_scheduler.cc:487
|
#10 0x0000556ed2e47631 in event_scheduler_thread (arg=0x145e0001a198) at /test/11.0_dbg/sql/event_scheduler.cc:236
|
#11 0x0000145e5003eb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
|
#12 0x0000145e500d0a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
|
Or this stack, but less frequently:
|
11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)
|
Core was generated by `/test/MD090123-mariadb-11.0.1-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
|
Program terminated with signal SIGABRT, Aborted.
|
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=22940532758080)
|
at ./nptl/pthread_kill.c:44
|
[Current thread is 1 (Thread 0x14dd424e5640 (LWP 3549264))]
|
(gdb) bt
|
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=22940532758080) at ./nptl/pthread_kill.c:44
|
#1 __pthread_kill_internal (signo=6, threadid=22940532758080) at ./nptl/pthread_kill.c:78
|
#2 __GI___pthread_kill (threadid=22940532758080, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
|
#3 0x000014dd5eff9476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
|
#4 0x000014dd5efdf7f3 in __GI_abort () at ./stdlib/abort.c:79
|
#5 0x00005619431169a9 in safe_mutex_lock (mp=0x561944a77460, my_flags=<optimized out>, file=0x5619433bf008 "/test/11.0_dbg/sql/event_scheduler.cc", line=733) at /test/11.0_dbg/mysys/thr_mutex.c:297
|
#6 0x0000561942c30198 in inline_mysql_mutex_lock (src_line=733, src_file=0x5619433bf008 "/test/11.0_dbg/sql/event_scheduler.cc", that=0x561944a77460) at /test/11.0_dbg/include/mysql/psi/mysql_thread.h:750
|
#7 Event_scheduler::lock_data (this=this@entry=0x561944a77460, func=func@entry=0x5619433bef20 "is_running", line=line@entry=609) at /test/11.0_dbg/sql/event_scheduler.cc:733
|
#8 0x0000561942c30210 in Event_scheduler::is_running (this=this@entry=0x561944a77460) at /test/11.0_dbg/sql/event_scheduler.cc:609
|
#9 0x0000561942c304f9 in Event_scheduler::run (this=this@entry=0x561944a77460, thd=0x14dd00023608) at /test/11.0_dbg/sql/event_scheduler.cc:487
|
#10 0x0000561942c30631 in event_scheduler_thread (arg=0x14dd0001a198) at /test/11.0_dbg/sql/event_scheduler.cc:236
|
#11 0x000014dd5f04bb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
|
#12 0x000014dd5f0dda00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
|
Or this stack, but also less frequently:
|
11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)
|
Core was generated by `/test/MD090123-mariadb-11.0.1-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 hashcmp (hash=hash@entry=0x556089c6b968, pos=pos@entry=0x8f8f8f8f0,
|
key=key@entry=0x556088a0db58 <LOCK_thread_id+120> "\005\001",
|
length=length@entry=8) at /test/11.0_dbg/mysys/hash.c:379
|
379 rec_key= (uchar*) my_hash_key(hash, pos->data, &rec_keylength, 1);
|
[Current thread is 1 (Thread 0x14b59262f640 (LWP 2940588))]
|
(gdb) bt
|
#0 hashcmp (hash=hash@entry=0x556089c6b968, pos=pos@entry=0x8f8f8f8f0, key=key@entry=0x556088a0db58 <LOCK_thread_id+120> "\005\001", length=length@entry=8) at /test/11.0_dbg/mysys/hash.c:379
|
#1 0x0000556087f71fec in my_hash_first_from_hash_value (hash=hash@entry=0x556089c6b968, hash_value=<optimized out>, key=key@entry=0x556088a0db58 <LOCK_thread_id+120> "\005\001", length=length@entry=8, current_record=current_record@entry=0x14b59262db7c) at /test/11.0_dbg/mysys/hash.c:290
|
#2 0x0000556087f7208d in my_hash_first (hash=0x556089c6b968, key=key@entry=0x556088a0db58 <LOCK_thread_id+120> "\005\001", length=length@entry=8, current_record=current_record@entry=0x14b59262db7c) at /test/11.0_dbg/mysys/hash.c:262
|
#3 0x0000556087f720ed in my_hash_search (hash=<optimized out>, key=key@entry=0x556088a0db58 <LOCK_thread_id+120> "\005\001", length=length@entry=8) at /test/11.0_dbg/mysys/hash.c:235
|
#4 0x0000556087f9091c in safe_mutex_lock (mp=0x556088a0dae0 <LOCK_thread_id>, my_flags=<optimized out>, file=0x556088051004 "/test/11.0_dbg/sql/mysqld.cc", line=9866) at /test/11.0_dbg/mysys/thr_mutex.c:335
|
#5 0x000055608750c349 in inline_mysql_mutex_lock (src_line=9866, src_file=0x556088051004 "/test/11.0_dbg/sql/mysqld.cc", that=0x556088a0dae0 <LOCK_thread_id>) at /test/11.0_dbg/include/mysql/psi/mysql_thread.h:750
|
#6 next_thread_id () at /test/11.0_dbg/sql/mysqld.cc:9866
|
#7 0x0000556087aaa2a0 in Event_scheduler::start (this=0x556089a48300, err_no=err_no@entry=0x14b59262dcbc) at /test/11.0_dbg/sql/event_scheduler.cc:404
|
#8 0x000055608775c8cf in Events::start (err_no=err_no@entry=0x14b59262dcbc) at /test/11.0_dbg/sql/events.cc:1136
|
#9 0x0000556087793b0d in event_scheduler_update (self=<optimized out>, thd=0x14b55c000d58, type=<optimized out>) at /test/11.0_dbg/sql/sys_vars.cc:1159
|
#10 0x000055608754e817 in sys_var::update (this=0x556088a39e40 <Sys_event_scheduler>, thd=0x14b55c000d58, var=0x14b55c013260) at /test/11.0_dbg/sql/set_var.cc:208
|
#11 0x000055608754ed07 in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/11.0_dbg/sql/set_var.cc:863
|
#12 0x000055608754ff30 in sql_set_variables (thd=thd@entry=0x14b55c000d58, var_list=var_list@entry=0x14b55c005ee8, free=free@entry=true) at /test/11.0_dbg/sql/set_var.cc:745
|
#13 0x000055608762a543 in mysql_execute_command (thd=thd@entry=0x14b55c000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/11.0_dbg/sql/sql_parse.cc:5038
|
#14 0x000055608762e934 in mysql_parse (thd=thd@entry=0x14b55c000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14b59262e2c0) at /test/11.0_dbg/sql/sql_parse.cc:8000
|
#15 0x0000556087630ac8 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14b55c000d58, packet=packet@entry=0x14b55c00ae09 "SET GLOBAL event_scheduler=TRUE", packet_length=packet_length@entry=31, blocking=blocking@entry=true) at /test/11.0_dbg/sql/sql_class.h:243
|
#16 0x0000556087632921 in do_command (thd=0x14b55c000d58, blocking=blocking@entry=true) at /test/11.0_dbg/sql/sql_parse.cc:1407
|
#17 0x000055608777c9ea in do_handle_one_connection (connect=<optimized out>, connect@entry=0x556089c6ba88, put_in_cache=put_in_cache@entry=true) at /test/11.0_dbg/sql/sql_connect.cc:1416
|
#18 0x000055608777cc4e in handle_one_connection (arg=0x556089c6ba88) at /test/11.0_dbg/sql/sql_connect.cc:1318
|
#19 0x000014b5aef46b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
|
#20 0x000014b5aefd8a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
|
|
|
In connection with the last comment, here is the code around /test/11.0_dbg/sql/event_scheduler.cc, line 733:
/*
|
Auxiliary function for locking LOCK_scheduler_state. Used
|
by the LOCK_DATA macro.
|
|
SYNOPSIS
|
Event_scheduler::lock_data()
|
func Which function is requesting mutex lock
|
line On which line mutex lock is requested
|
*/
|
|
void
|
Event_scheduler::lock_data(const char *func, uint line)
|
{
|
DBUG_ENTER("Event_scheduler::lock_data");
|
DBUG_PRINT("enter", ("func=%s line=%u", func, line));
|
mysql_mutex_lock(&LOCK_scheduler_state); ### <<<<-------- Line 733
|
mutex_last_locked_in_func= func;
|
mutex_last_locked_at_line= line;
|
mutex_scheduler_data_locked= TRUE;
|
DBUG_VOID_RETURN;
|
}
|
|
|
The issue seems to be straightforward - an attempt [race?] to lock a mutex after shutdown was already initiated. Perhaps the solution is adding a check, or preventing the race?
Another thought (based on seeing other bugs in this area, but not directly related here) would be for the scheduler to always check whether a shutdown is in progress and not start executing a query if so.
|
|
I have also seen an optimized 11.0.1 build (rev b075191ba8598af6aff5549e6e19f6255aef258a) crash without a core file (not normal) and without any message in the error log (on more than one occasion).
|
|
Given the stack smashing I ran the testcase through a ASAN+UBSAN build, and there is a heap-use-after-free:
|
10.11.2 70be59913c90e93fe5136d6f6df03c4254aa515d (Optimized, UBASAN)
|
==2890587==ERROR: AddressSanitizer: heap-use-after-free on address 0x60f000001248 at pc 0x559209b23cf7 bp 0x14d0e84e4260 sp 0x14d0e84e4250
|
WRITE of size 8 at 0x60f000001248 thread T15
|
#0 0x559209b23cf6 in Event_scheduler::start(int*) /test/10.11_opt_san/sql/event_scheduler.cc:433
|
#1 0x5592080c4ad8 in event_scheduler_update /test/10.11_opt_san/sql/sys_vars.cc:1159
|
#2 0x5592070a5afa in sys_var::update(THD*, set_var*) /test/10.11_opt_san/sql/set_var.cc:208
|
#3 0x5592070a9336 in set_var::update(THD*) /test/10.11_opt_san/sql/set_var.cc:863
|
#4 0x5592070b1b6d in sql_set_variables(THD*, List<set_var_base>*, bool) /test/10.11_opt_san/sql/set_var.cc:745
|
#5 0x559207727f06 in mysql_execute_command(THD*, bool) /test/10.11_opt_san/sql/sql_parse.cc:5038
|
#6 0x559207740d82 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/10.11_opt_san/sql/sql_parse.cc:8000
|
#7 0x55920774e7e5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/10.11_opt_san/sql/sql_parse.cc:1894
|
#8 0x559207757f40 in do_command(THD*, bool) /test/10.11_opt_san/sql/sql_parse.cc:1407
|
#9 0x55920803471c in do_handle_one_connection(CONNECT*, bool) /test/10.11_opt_san/sql/sql_connect.cc:1416
|
#10 0x559208036d1c in handle_one_connection /test/10.11_opt_san/sql/sql_connect.cc:1318
|
#11 0x14d10a809b42 in start_thread nptl/pthread_create.c:442
|
#12 0x14d10a89b9ff (/lib/x86_64-linux-gnu/libc.so.6+0x1269ff)
|
|
0x60f000001248 is located 56 bytes inside of 168-byte region [0x60f000001210,0x60f0000012b8)
|
freed by thread T0 here:
|
#0 0x559206e6ed07 in operator delete(void*) (/test/UBASAN_MD070123-mariadb-10.11.2-linux-x86_64-opt/bin/mariadbd+0x7a22d07)
|
#1 0x559207f7ce99 in Events::deinit() /test/10.11_opt_san/sql/events.cc:1000
|
#2 0x559206edc2de in close_connections /test/10.11_opt_san/sql/mysqld.cc:1788
|
#3 0x559206edc2de in mysqld_main(int, char**) /test/10.11_opt_san/sql/mysqld.cc:6022
|
#4 0x14d10a79ed8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58
|
|
previously allocated by thread T0 here:
|
#0 0x559206e6e1e7 in operator new(unsigned long) (/test/UBASAN_MD070123-mariadb-10.11.2-linux-x86_64-opt/bin/mariadbd+0x7a221e7)
|
#1 0x559207f828a2 in Events::init(THD*, bool) /test/10.11_opt_san/sql/events.cc:958
|
#2 0x559206edae2e in mysqld_main(int, char**) /test/10.11_opt_san/sql/mysqld.cc:5887
|
#3 0x14d10a79ed8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58
|
|
Thread T15 created by T0 here:
|
#0 0x559206e106c5 in pthread_create (/test/UBASAN_MD070123-mariadb-10.11.2-linux-x86_64-opt/bin/mariadbd+0x79c46c5)
|
#1 0x559206ec4cfe in create_thread_to_handle_connection(CONNECT*) /test/10.11_opt_san/sql/mysqld.cc:6102
|
#2 0x559206ed712f in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /test/10.11_opt_san/sql/mysqld.cc:6223
|
#3 0x559206ed80b7 in handle_connections_sockets() /test/10.11_opt_san/sql/mysqld.cc:6347
|
#4 0x559206edb11d in mysqld_main(int, char**) /test/10.11_opt_san/sql/mysqld.cc:5997
|
#5 0x14d10a79ed8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58
|
|
SUMMARY: AddressSanitizer: heap-use-after-free /test/10.11_opt_san/sql/event_scheduler.cc:433 in Event_scheduler::start(int*)
|
Shadow bytes around the buggy address:
|
0x0c1e7fff81f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 fa fa fa
|
0x0c1e7fff8200: fa fa fa fa fa fa fd fd fd fd fd fd fd fd fd fd
|
0x0c1e7fff8210: fd fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa
|
0x0c1e7fff8220: fa fa fa fa 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c1e7fff8230: 00 00 00 00 00 00 00 00 00 fa fa fa fa fa fa fa
|
=>0x0c1e7fff8240: fa fa fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd
|
0x0c1e7fff8250: fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa fa
|
0x0c1e7fff8260: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c1e7fff8270: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c1e7fff8280: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c1e7fff8290: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
Shadow byte legend (one shadow byte represents 8 application bytes):
|
Addressable: 00
|
Partially addressable: 01 02 03 04 05 06 07
|
Heap left redzone: fa
|
Freed heap region: fd
|
Stack left redzone: f1
|
Stack mid redzone: f2
|
Stack right redzone: f3
|
Stack after return: f5
|
Stack use after scope: f8
|
Global redzone: f9
|
Global init order: f6
|
Poisoned by user: f7
|
Container overflow: fc
|
Array cookie: ac
|
Intra object redzone: bb
|
ASan internal: fe
|
Left alloca redzone: ca
|
Right alloca redzone: cb
|
Shadow gap: cc
|
==2890587==ABORTING
|
230118 19:59:08 [ERROR] mysqld got signal 6 ;
|
|