If SHOW BINLOGS / performance_schema.global_status query, and a transaction commit run in parallel, they may deadlock as follows:
Thread 2266 (Thread 0x7e8bdff7d700 (LWP 17122)):
#0 0x00007f663b754f4d in __lll_lock_wait () from /lib64/libpthread.so.0
#1 0x00007f663b750d38 in _L_lock_975 () from /lib64/libpthread.so.0
#2 0x00007f663b750ce1 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3 0x0000000000e994ce in native_mutex_lock (mutex=0x7e87a81d77d8) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/thr_mutex.h:84
#4 my_mutex_lock (mp=0x7e87a81d77d8) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/thr_mutex.h:182
#5 inline_mysql_mutex_lock (src_file=0x15c56b0 "/mnt/workspace/percona-server-5.7-redhat-binary/label_exp/centos7-64/rpmbuild/BUILD/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc", src_line=2595, that=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/mysql/psi/mysql_thread.h:715
#6 Log_in_use::operator() (this=0x7e8bdff79800, thd=0x7e87a81d6aa0) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc:2595
#7 0x000000000079bc19 in operator() (thd=<optimized out>, this=<synthetic pointer>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/mysqld_thd_manager.cc:46
#8 for_each<THD**, Do_THD> (__f=..., __last=0x7e88410301f0, __first=0x7e884102f828) at /usr/include/c++/4.8.2/bits/stl_algo.h:4417
#9 Global_THD_manager::do_for_all_thd (this=0x393f870, func=func@entry=0x7e8bdff79800) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/mysqld_thd_manager.cc:273
#10 0x0000000000e95028 in log_in_use (log_name=0x7e8bdff798e0 "./mysql-bin.000384") at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc:2621
#11 MYSQL_BIN_LOG::purge_logs_before_date (this=this@entry=0x1e55c80 <mysql_bin_log>, purge_time=purge_time@entry=1483246200, auto_purge=auto_purge@entry=true) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc:6446
#12 0x0000000000e95522 in MYSQL_BIN_LOG::purge (this=this@entry=0x1e55c80 <mysql_bin_log>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc:7320
#13 0x0000000000e968a3 in MYSQL_BIN_LOG::ordered_commit (this=this@entry=0x1e55c80 <mysql_bin_log>, thd=thd@entry=0x7e8fc81c4f50, all=all@entry=false, skip_commit=skip_commit@entry=false) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc:9365
#14 0x0000000000e982e3 in MYSQL_BIN_LOG::commit (this=0x1e55c80 <mysql_bin_log>, thd=0x7e8fc81c4f50, all=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc:8426
#15 0x00000000007febe1 in ha_commit_trans (thd=thd@entry=0x7e8fc81c4f50, all=all@entry=false, ignore_global_read_lock=ignore_global_read_lock@entry=false) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/handler.cc:1818
#16 0x0000000000d7b79e in trans_commit_stmt (thd=thd@entry=0x7e8fc81c4f50) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/transaction.cc:458
#17 0x0000000000ccb14a in mysql_execute_command (thd=0x7e8fc81c4f50, first_level=first_level@entry=true) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:5241
#18 0x0000000000cfd2b7 in Prepared_statement::execute (this=this@entry=0x7e8fc81926f0, expanded_query=expanded_query@entry=0x7e8bdff7c2b0, open_cursor=open_cursor@entry=false) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_prepare.cc:4281
#19 0x0000000000cfd6ca in Prepared_statement::execute_loop (this=0x7e8fc81926f0, expanded_query=0x7e8bdff7c2b0, open_cursor=<optimized out>, packet=<optimized out>, packet_end=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_prepare.cc:3889
#20 0x0000000000cfda0b in mysqld_stmt_execute (thd=thd@entry=0x7e8fc81c4f50, stmt_id=<optimized out>, flags=0, params=0x7e8fc80008ea "", params_length=36) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_prepare.cc:2679
#21 0x0000000000cd38cc in dispatch_command (thd=thd@entry=0x7e8fc81c4f50, com_data=com_data@entry=0x7e8bdff7cce0, command=COM_STMT_EXECUTE) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:1381
#22 0x0000000000cd47ef in do_command (thd=thd@entry=0x7e8fc81c4f50) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:1010
#23 0x0000000000d9ad28 in handle_connection (arg=arg@entry=0x4f74190) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/conn_handler/connection_handler_per_thread.cc:312
#24 0x0000000000f2a004 in pfs_spawn_thread (arg=0x4f741e0) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/storage/perfschema/pfs.cc:2188
#25 0x00007f663b74edc5 in start_thread () from /lib64/libpthread.so.0
#26 0x00007f663999fced in clone () from /lib64/libc.so.6
Thread 1984 (Thread 0x7e8bd77df700 (LWP 17404)):
#0 0x00007f663b754f4d in __lll_lock_wait () from /lib64/libpthread.so.0
#1 0x00007f663b750d02 in _L_lock_791 () from /lib64/libpthread.so.0
#2 0x00007f663b750c08 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3 0x0000000000e8ea05 in native_mutex_lock (mutex=0x1e55c88 <mysql_bin_log+8>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/thr_mutex.h:84
#4 my_mutex_lock (mp=0x1e55c88 <mysql_bin_log+8>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/thr_mutex.h:182
#5 inline_mysql_mutex_lock (src_file=0x15c56b0 "/mnt/workspace/percona-server-5.7-redhat-binary/label_exp/centos7-64/rpmbuild/BUILD/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc", src_line=9528, that=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/mysql/psi/mysql_thread.h:715
#6 MYSQL_BIN_LOG::set_status_variables (this=this@entry=0x1e55c80 <mysql_bin_log>, thd=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc:9528
#7 0x0000000000e8eb9b in show_binlog_vars (thd=<optimized out>, var=0x7e8bd77dc4e0, buff=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.cc:11914
#8 0x0000000000f56c17 in PFS_status_variable_cache::manifest (this=this@entry=0x7e87a84fdde8, thd=0x7e87a81d6aa0, show_var_array=<optimized out>, status_vars=0x7e8bd77ddc10, prefix=prefix@entry=0x1532ee3 "", nested_array=nested_array@entry=false, strict=strict@entry=false) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/storage/perfschema/pfs_variable.cc:1174
#9 0x0000000000f56e14 in PFS_status_variable_cache::do_materialize_all (this=0x7e87a84fdde8, unsafe_thd=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/storage/perfschema/pfs_variable.cc:999
#10 0x0000000000f8098a in materialize_all (unsafe_thd=<optimized out>, this=0x7e87a84fdde8) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/storage/perfschema/pfs_variable.h:521
#11 table_session_status::rnd_init (this=0x7e87a84fddc0, scan=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/storage/perfschema/table_session_status.cc:93
#12 0x0000000000f2888c in ha_perfschema::rnd_init (this=0x7e87a81f1c60, scan=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/storage/perfschema/ha_perfschema.cc:324
#13 0x00000000007ffeb9 in handler::ha_rnd_init (this=0x7e87a81f1c60, scan=scan@entry=true) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/handler.cc:3049
#14 0x0000000000c32f03 in init_read_record (info=info@entry=0x7e87a8953a70, thd=0x7e87a81d6aa0, table=0x7e87a81920c0, table@entry=0x0, qep_tab=qep_tab@entry=0x7e87a8953a20, use_record_cache=use_record_cache@entry=1, print_error=print_error@entry=true, disable_rr_cache=<optimized out>, disable_rr_cache@entry=false) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/records.cc:314
#15 0x0000000000c9f4ce in join_init_read_record (tab=0x7e87a8953a20) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:2477
#16 0x0000000000ca2fab in sub_select (join=0x7e87a8953340, qep_tab=0x7e87a8953a20, end_of_records=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:1271
#17 0x0000000000c9bb87 in do_select (join=0x7e87a8953340) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:944
#18 JOIN::exec (this=this@entry=0x7e87a8953340) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:199
#19 0x0000000000c97b34 in TABLE_LIST::materialize_derived (this=this@entry=0x7e87a8914d68, thd=thd@entry=0x7e87a81d6aa0) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_derived.cc:326
#20 0x0000000000c9c5af in join_materialize_derived (tab=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:2499
#21 0x0000000000c9c0a2 in QEP_TAB::prepare_scan (this=0x7e87a8954170) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:1325
#22 0x0000000000ca2ed0 in sub_select (join=0x7e87a8952f60, qep_tab=0x7e87a8954170, end_of_records=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:1225
#23 0x0000000000c9bb87 in do_select (join=0x7e87a8952f60) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:944
#24 JOIN::exec (this=0x7e87a8952f60) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_executor.cc:199
#25 0x0000000000d0d66d in handle_query (thd=thd@entry=0x7e87a81d6aa0, lex=lex@entry=0x7e87a81d8e78, result=result@entry=0x7e87a8925f00, added_options=added_options@entry=0, removed_options=removed_options@entry=0) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_select.cc:184
#26 0x000000000075cf8f in execute_sqlcom_select (thd=thd@entry=0x7e87a81d6aa0, all_tables=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:5393
#27 0x0000000000ccbb41 in mysql_execute_command (thd=thd@entry=0x7e87a81d6aa0, first_level=first_level@entry=true) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:2844
#28 0x0000000000cd244d in mysql_parse (thd=thd@entry=0x7e87a81d6aa0, parser_state=parser_state@entry=0x7e8bd77de400) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:5838
#29 0x0000000000cd2e0f in dispatch_command (thd=thd@entry=0x7e87a81d6aa0, com_data=com_data@entry=0x7e8bd77dece0, command=COM_QUERY) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:1447
#30 0x0000000000cd47ef in do_command (thd=thd@entry=0x7e87a81d6aa0) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:1010
#31 0x0000000000d9ad28 in handle_connection (arg=arg@entry=0x4c8a220) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/conn_handler/connection_handler_per_thread.cc:312
#32 0x0000000000f2a004 in pfs_spawn_thread (arg=0x4fb7a60) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/storage/perfschema/pfs.cc:2188
#33 0x00007f663b74edc5 in start_thread () from /lib64/libpthread.so.0
#34 0x00007f663999fced in clone () from /lib64/libc.so.6
Thread 357 (Thread 0x7e8ba5aac700 (LWP 19406)):
#0 0x00007f663b754f4d in __lll_lock_wait () from /lib64/libpthread.so.0
#1 0x00007f663b750d02 in _L_lock_791 () from /lib64/libpthread.so.0
#2 0x00007f663b750c08 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3 0x0000000000ea4add in native_mutex_lock (mutex=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/thr_mutex.h:84
#4 my_mutex_lock (mp=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/thr_mutex.h:182
#5 inline_mysql_mutex_lock (src_line=916, src_file=0x13258b0 "/mnt/workspace/percona-server-5.7-redhat-binary/label_exp/centos7-64/rpmbuild/BUILD/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.h", that=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/include/mysql/psi/mysql_thread.h:715
#6 lock_index (this=<optimized out>) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/binlog.h:916
#7 show_binlogs (thd=thd@entry=0x7e88f412f7d0) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/rpl_master.cc:709
#8 0x0000000000ccc907 in mysql_execute_command (thd=thd@entry=0x7e88f412f7d0, first_level=first_level@entry=true) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:3599
#9 0x0000000000cd244d in mysql_parse (thd=thd@entry=0x7e88f412f7d0, parser_state=parser_state@entry=0x7e8ba5aab400) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:5838
#10 0x0000000000cd2e0f in dispatch_command (thd=thd@entry=0x7e88f412f7d0, com_data=com_data@entry=0x7e8ba5aabce0, command=COM_QUERY) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:1447
#11 0x0000000000cd47ef in do_command (thd=thd@entry=0x7e88f412f7d0) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/sql_parse.cc:1010
#12 0x0000000000d9ad28 in handle_connection (arg=arg@entry=0x4264c10) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/sql/conn_handler/connection_handler_per_thread.cc:312
#13 0x0000000000f2a004 in pfs_spawn_thread (arg=0x4fdca00) at /usr/src/debug/percona-server-5.7.16-10/percona-server-5.7.16-10/storage/perfschema/pfs.cc:2188
#14 0x00007f663b74edc5 in start_thread () from /lib64/libpthread.so.0
#15 0x00007f663999fced in clone () from /lib64/libc.so.6
The above threads:
Thread 2266: tries to lock thd->LOCK_thd_data
has LOCK_index
Thread 1984: tries to lock LOCK_log
has thd->LOCK_thd_data
Thread 357: tries to lock LOCK_index
has LOCK_log
resulting in a deadlock: 1984 -> 357 -> 2266 -> 1984.
This is a regression in Percona Server caused by binlog status variable introduction (Binlog_snapshot_file and Binlog_snapshot_position), which makes thread 1984 to try to lock LOCK_log.
Split from bug 1646100
https:/
https:/