MySQL Bugs: #95133: Deadlock during binlog purge

Bug #95133	Deadlock during binlog purge - rotate
Submitted:	25 Apr 2019 12:21	Modified:	27 May 2019 12:20
Reporter:	Bernardo Perez	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server	Severity:	S3 (Non-critical)
Version:	8.0.13	OS:	Linux
Assigned to:		CPU Architecture:	x86

Description:
Hello,

this seems related to: 
https://bugs.mysql.com/bug.php?id=91941
https://bugs.mysql.com/bug.php?id=92108

But it is not exactly the same so decided to report to confirm and just in case we are facing a new problem.

The process remained hang without processing work or accepting new connections for nearly 5 hours. 

Will upload pstack

How to repeat:
This happened on production server

Thread 1212 (Thread 0x2b278f750700 (LWP 14307)):
#0  0x00002b276988af4d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00002b2769886d02 in _L_lock_791 () from /lib64/libpthread.so.0
#2  0x00002b2769886c08 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x0000000000e80eb9 in PolyLock_lock_log::rdlock() ()
#4  0x0000000000d4117d in sys_var::value_ptr(THD*, THD*, enum_var_type, MYSQL_LEX_STRING*) ()
#5  0x0000000000e1a87d in get_one_variable_ext(THD*, THD*, SHOW_VAR const*, enum_var_type, enum_mysql_show_type, System_status_var*, CHARSET_INFO const**, char*, unsigned long*, bool*) ()
#6  0x0000000002189126 in System_variable::init(THD*, SHOW_VAR const*, enum_var_type) ()
#7  0x00000000021896df in PFS_system_variable_cache::do_materialize_all(THD*) ()
#8  0x00000000021ca33b in table_session_variables::rnd_init(bool) ()
#9  0x000000000215f3f9 in ha_perfschema::rnd_init(bool) ()
#10 0x0000000000fbdba9 in handler::ha_rnd_init(bool) ()
#11 0x0000000000d2bd03 in TableScanIterator::Init() ()
#12 0x0000000000d90af6 in sub_select(JOIN*, QEP_TAB*, bool) ()
#13 0x0000000000d8d44d in JOIN::exec() ()
#14 0x000000000115b42e in TABLE_LIST::materialize_derived(THD*) ()
#15 0x0000000000d8754f in join_materialize_derived(QEP_TAB*) ()
#16 0x0000000000d907a3 in QEP_TAB::prepare_scan() ()
#17 0x0000000000d90978 in sub_select(JOIN*, QEP_TAB*, bool) ()
#18 0x0000000000d8d44d in JOIN::exec() ()
#19 0x0000000000e06428 in handle_query(THD*, LEX*, Query_result*, unsigned long long, unsigned long long) ()
#20 0x0000000000dba2a8 in execute_show(THD*, TABLE_LIST*) ()
#21 0x0000000000dc26d8 in mysql_execute_command(THD*, bool) ()
#22 0x0000000000dc370f in mysql_parse(THD*, Parser_state*, bool) ()
#23 0x0000000000dc67ab in dispatch_command(THD*, COM_DATA const*, enum_server_command) ()
#24 0x0000000000dc7289 in do_command(THD*) ()
#25 0x0000000000ec00c8 in handle_connection ()
#26 0x00000000021617f7 in pfs_spawn_thread ()
#27 0x00002b2769884dc5 in start_thread () from /lib64/libpthread.so.0
#28 0x00002b276a6c9c9d in clone () from /lib64/libc.so.6

Thread 1216 (Thread 0x2b276e085700 (LWP 6309)):
#0  0x00002b276988af4d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00002b2769886d38 in _L_lock_975 () from /lib64/libpthread.so.0
#2  0x00002b2769886ce1 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000019c5f18 in Adjust_offset::operator()(THD*) ()
#4  0x0000000000cf429f in Global_THD_manager::do_for_all_thd(Do_THD_Impl*) ()
#5  0x00000000019ca77e in MYSQL_BIN_LOG::remove_logs_from_index(LOG_INFO*, bool) ()
#6  0x00000000019d9052 in MYSQL_BIN_LOG::purge_logs(char const*, bool, bool, bool, unsigned long long*, bool) ()
#7  0x00000000019d947b in purge_master_logs(THD*, char const*) ()
#8  0x0000000000dc17c8 in mysql_execute_command(THD*, bool) ()
#9  0x0000000000dc370f in mysql_parse(THD*, Parser_state*, bool) ()
#10 0x0000000000dc67ab in dispatch_command(THD*, COM_DATA const*, enum_server_command) ()
#11 0x0000000000dc7289 in do_command(THD*) ()
#12 0x0000000000ec00c8 in handle_connection ()
#13 0x00000000021617f7 in pfs_spawn_thread ()
#14 0x00002b2769884dc5 in start_thread () from /lib64/libpthread.so.0
#15 0x00002b276a6c9c9d in clone () from /lib64/libc.so.6

Thread 1213 (Thread 0x2b27871f2700 (LWP 14000)):
#0  0x00002b276988af4d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00002b2769886d38 in _L_lock_975 () from /lib64/libpthread.so.0
#2  0x00002b2769886ce1 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x000000000105d4c8 in long long Item_func_get_system_var::get_sys_var_safe<bool>(THD*) ()
#4  0x000000000105d583 in Item_func_get_system_var::val_int() ()
#5  0x0000000000fe4217 in Item::send(Protocol*, String*) ()
#6  0x0000000000d710fb in THD::send_result_set_row(List<Item>*) ()
#7  0x0000000001124e67 in Query_result_send::send_data(List<Item>&) ()
#8  0x0000000000d8d694 in JOIN::exec() ()
#9  0x0000000000e06634 in Sql_cmd_dml::execute_inner(THD*) ()
#10 0x0000000000e0e000 in Sql_cmd_dml::execute(THD*) ()
#11 0x0000000000dc0591 in mysql_execute_command(THD*, bool) ()
#12 0x0000000000dc370f in mysql_parse(THD*, Parser_state*, bool) ()
#13 0x0000000000dc67ab in dispatch_command(THD*, COM_DATA const*, enum_server_command) ()
#14 0x0000000000dc7289 in do_command(THD*) ()
#15 0x0000000000ec00c8 in handle_connection ()
#16 0x00000000021617f7 in pfs_spawn_thread ()
#17 0x00002b2769884dc5 in start_thread () from /lib64/libpthread.so.0
#18 0x00002b276a6c9c9d in clone () from /lib64/libc.so.6
Thread 1212 (Thread 0x2b278f750700 (LWP 14307)):

Pstack of all threads during the issue

Attachment: pstack_95133.txt (text/plain), 935.67 KiB.

ptpmp during the issue

Attachment: ptpmp_95133.txt (text/plain), 9.45 KiB.

Hi,

Thank you for your bug report.

I can confirm that your report is not a duplicate of neither of the two bugs that you have mentioned.

I also must inform you that we can not verify any bug based solely on the stack traces.

We need a fully repeatable test case. This test case must contain all the tables, their contents and commands that should be executed concurrently in order to produce the same result as the one in your stack trace files.

Thank you in advance.

Hello,

You mentioned:

"I also must inform you that we can not verify any bug based solely on
the stack traces.

We need a fully repeatable test case. This test case must contain all the tables, their contents and commands that should be executed concurrently in order to produce the same result as the one in your stack trace files."

In the bug that I've associated to this one:

https://bugs.mysql.com/bug.php?id=91941 

There is no repeatable case and it was diagnosed as a deadlock by Shane Bester and then you marked it as a bug. 

"We had to do a very careful analysis of your thread stacks in order to discover that this is ultimately a bug."

Why there is a different approach here?

The answer is quite simple.

In the bug that you have mentioned, three of us were able to find the common denominator for the waiting locks. 

In your case, it is nay impossible to find a connection between a read-only query, performance schema update and (session or user) variable assignment.

We are waiting on your test case.

One more item.

There were several GIS bugs fixed between 8.0.13 and 8.0.16 and we do not feel like chasing old bugs.

We recommend that you try 8.0.16.

No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".