Bug #92108 | Deadlock by concurrent show binlogs, pfs session_variables table & binlog purge | ||
---|---|---|---|
Submitted: | 21 Aug 2018 17:48 | Modified: | 1 Oct 2018 19:36 |
Reporter: | Shashank Sahni (OCA) | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: Logging | Severity: | S2 (Serious) |
Version: | 5.7.22 | OS: | Any |
Assigned to: | CPU Architecture: | Any | |
Tags: | binlog, performance_schema |
[21 Aug 2018 17:48]
Shashank Sahni
[21 Aug 2018 17:51]
Shashank Sahni
Test to reproduce this deadlock (*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.
Contribution: binlog_deadlock.patch (application/octet-stream, text), 3.96 KiB.
[21 Aug 2018 17:54]
Shashank Sahni
This test contributed is based on a similar deadlock bug test case in percona's mysql distribution https://github.com/percona/percona-server/pull/1305/files
[22 Aug 2018 7:35]
MySQL Verification Team
https://bugs.mysql.com/bug.php?id=91941
[22 Aug 2018 12:04]
MySQL Verification Team
Hi, Thank you for your bug report. This seems like a duplicate of the bug: https://bugs.mysql.com/bug.php?id=91941 However, since this report is much more clear and is a bit different, I will set it to "Verified" and not to "Duplicate".
[28 Aug 2018 22:52]
Shashank Sahni
Any updates here. The issue I see here is the requirement of Lock_log while reading sys_variables. Here is the relevant Polylock_lock_log defined in sys_var.c void PolyLock_lock_log::rdlock() { mysql_mutex_lock(mysql_bin_log.get_log_lock()); } Currently, only the two "binlog_transaction_dependency_*" variables use it. Could someone confirm if the log_lock needs to be acquired for reading these sys variables too? Ref - https://github.com/mysql/mysql-server/blob/mysql-5.7.22/sql/sys_vars.cc#L3588-L3591
[29 Aug 2018 11:33]
MySQL Verification Team
Yes, it has to be acquired for safety reasons. But, it is a read lock only ......
[19 Sep 2018 21:26]
Stephen Griffin
Any update on this issue? Running into the same problem when mysql just hangs. [root@tr2-mysql01 (sandbox) data]# pt-pmp -b mysqld Wed Sep 19 11:20:18 EDT 2018 1218 __lll_lock_wait(libpthread.so.0),_L_lock_1022(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),THD::init,THD::THD,Channel_info::create_thd,Channel_info_tcpip_socket::create_thd,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 269 __lll_lock_wait(libpthread.so.0),_L_lock_1022(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),THD::init,THD::THD,Channel_info::create_thd,Channel_info_local_socket::create_thd,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 10 nanosleep(libpthread.so.0),os_thread_sleep,buf_lru_manager,start_thread(libpthread.so.0),clone(libc.so.6) 10 __io_getevents_0_4(libaio.so.1),LinuxAIOHandler::collect,LinuxAIOHandler::poll,os_aio_handler,fil_aio_wait,io_handler_thread,start_thread(libpthread.so.0),clone(libc.so.6) 5 __lll_lock_wait(libpthread.so.0),_L_lock_1022(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),THD::release_resources,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 3 pthread_cond_wait,os_event::wait_low,buf_flush_page_cleaner_worker,start_thread(libpthread.so.0),clone(libc.so.6) 2 __lll_lock_wait(libpthread.so.0),_L_lock_1022(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),Item_func_get_system_var::fix_length_and_dec,Item_func::fix_fields,setup_fields,st_select_lex::prepare,handle_query,execute_sqlcom_select,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 sigwait(libpthread.so.0),signal_hand,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 sigwaitinfo(libc.so.6),timer_notify_thread_func,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_wait,Stage_manager::enroll_for,MYSQL_BIN_LOG::change_stage,MYSQL_BIN_LOG::ordered_commit,MYSQL_BIN_LOG::commit,ha_commit_trans,trans_commit_stmt,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_wait,os_event::wait_low,srv_purge_coordinator_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_wait,os_event::wait_low,buf_resize_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_wait,os_event::wait_low,buf_dump_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_wait,compress_gtid_table,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_timedwait,os_event::timed_wait,os_event::wait_time_low,srv_monitor_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_timedwait,os_event::timed_wait,os_event::wait_time_low,srv_error_monitor_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_timedwait,os_event::timed_wait,os_event::wait_time_low,lock_wait_timeout_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_timedwait,os_event::timed_wait,os_event::wait_time_low,ib_wqueue_timedwait,fts_optimize_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_timedwait,os_event::timed_wait,os_event::wait_time_low,dict_stats_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 pthread_cond_timedwait,os_event::timed_wait,os_event::wait_time_low,buf_flush_page_cleaner_coordinator,start_thread(libpthread.so.0),clone(libc.so.6) 1 poll(libc.so.6),vio_io_wait,vio_socket_io_wait,vio_read,net_read_raw_loop,net_read_packet,my_net_read,Protocol_classic::read_packet,Protocol_classic::get_command,do_command,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 poll(libc.so.6),Mysqld_socket_listener::listen_for_connection_event,mysqld_main,__libc_start_main(libc.so.6),_start 1 nanosleep(libpthread.so.0),os_thread_sleep,srv_master_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 __lll_lock_wait(libpthread.so.0),_L_lock_812(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),PolyLock_lock_log::rdlock,sys_var::value_ptr,get_one_variable_ext,System_variable::init,PFS_system_variable_cache::do_materialize_all,table_session_variables::rnd_init,ha_perfschema::rnd_init,handler::ha_rnd_init,init_read_record,join_init_read_record,sub_select,JOIN::exec,handle_query,execute_sqlcom_select,mysql_execute_command,Prepared_statement::execute,Prepared_statement::execute_loop,mysql_sql_stmt_execute,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 __lll_lock_wait(libpthread.so.0),_L_lock_812(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),MYSQL_BIN_LOG::change_stage,MYSQL_BIN_LOG::ordered_commit,MYSQL_BIN_LOG::commit,ha_commit_trans,trans_commit_stmt,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 __lll_lock_wait(libpthread.so.0),_L_lock_1022(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),show_status_array,show_status_array,fill_status,do_fill_table,get_schema_tables_result,JOIN::prepare_result,JOIN::exec,handle_query,execute_sqlcom_select,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 __lll_lock_wait(libpthread.so.0),_L_lock_1022(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),MYSQL_BIN_LOG::publish_coordinates_for_global_status,MYSQL_BIN_LOG::ordered_commit,MYSQL_BIN_LOG::commit,ha_commit_trans,trans_commit_stmt,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) 1 __lll_lock_wait(libpthread.so.0),_L_lock_1022(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),Item_func_get_system_var::fix_length_and_dec,Item_func::fix_fields,Item_func::fix_func_arg,Item_func::fix_fields,setup_fields,mysql_prepare_update,mysql_update,Sql_cmd_update::try_single_table_update,Sql_cmd_update::execute,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_connection,pfs_spawn_thread,start_thread(libpthread.so.0),clone(libc.so.6) [root@tr2-mysql01 (sandbox) data]#
[24 Sep 2018 14:41]
MySQL Verification Team
No news on this bug. Scheduling the bug fixing is the internal matter in our Engineering team. When the bug gets fixed, it will be announced here, on this page.
[1 Oct 2018 19:36]
Margaret Fisher
Posted by developer: Changelog entry added for MySQL 8.0.14 and 5.7.25: When the system variables binlog_transaction_dependency_tracking and binlog_transaction_dependency_history_size were set or read, the types of lock that were required could result in a deadlock scenario, because the same locks were also required for working with the active binary logs. A new lock type is now used instead for access to the transaction dependency tracking system variables, so that this deadlock cannot occur.
[19 Oct 2018 12:19]
MySQL Verification Team
Bug #92858 is a duplicate of this one.
[29 Nov 2023 11:20]
MySQL Verification Team
Hi, This bug is fixed 5 (five) years ago and 5.7 is no longer maintained. This bug is closed.