Query cache usage can cause hanging

Bug #359162 reported by Seppo Jaakola
2
Affects Status Importance Assigned to Milestone
MySQL patches by Codership
Fix Released
Low
Seppo Jaakola
0.8
Fix Released
Low
Seppo Jaakola

Bug Description

Observed with sqlgen testing a hanging situation, when query cache was enabled. Following sqlgen parameters used:
* tables 50
* rows 1000
* nodes 2
* users 10
* r/w ratio: 50/50
* trans-min 2, tans-max 4

Query cache was enable on both nodes.

Both nodes were hanging after few minutes of test running

Revision history for this message
Seppo Jaakola (seppo-jaakola) wrote :

Problem does not reproduce with debug build.

gdb session shows that other node has a hanging slave applier thread inside Query_cache::invalidate_table()

Changed in codership-mysql:
assignee: nobody → seppo-jaakola
importance: Undecided → Low
milestone: none → 0.6.1
status: New → In Progress
Revision history for this message
Seppo Jaakola (seppo-jaakola) wrote :

Here is the stack trace of the hanging slave applier:

(gdb) bt
#0 0x004c0402 in __kernel_vsyscall ()
#1 0x00c582c6 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/i686/nosegneg/libpthread.so.0
#2 0x0832e454 in Query_cache::invalidate_table ()
#3 0x0832e9de in Query_cache::invalidate_locked_for_write ()
#4 0x082bd21e in Rows_log_event::do_apply_event ()
#5 0x082c52be in wsrep_bf_execute_cb_rbr ()

Revision history for this message
Seppo Jaakola (seppo-jaakola) wrote :

Possibly relates to mysql bug: http://bugs.mysql.com/bug.php?id=43758

In our test case, slave applier is also waiting on condition: COND_cache_status_changed, but
somehow misses the signal.

Changed in codership-mysql:
milestone: 0.6.1 → 0.7
Changed in codership-mysql:
milestone: 0.7 → 0.8
Changed in codership-mysql:
status: In Progress → Confirmed
Changed in codership-mysql:
milestone: 0.8 → none
Revision history for this message
Teemu Ollakka (teemu-ollakka) wrote :

Got hang when query cache was enabled, managed to save the following backtraces:

#0 __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:136
#1 0x00007f5619cf560f in _L_lock_1172 () from /lib/libpthread.so.0
#2 0x00007f5619cf555a in __pthread_mutex_lock (mutex=0x7f5604058470)
    at pthread_mutex_lock.c:101
#3 0x00000000007767b8 in wsrep_innobase_kill_one_trx ()
#4 0x00000000007ce4bd in ?? ()
#5 0x00000000007d0ec2 in ?? ()
#6 0x00000000007d1991 in lock_clust_rec_read_check_and_lock ()
#7 0x0000000000808923 in ?? ()
#8 0x000000000080b67e in row_search_for_mysql ()
#9 0x0000000000777ebc in ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function) ()
#10 0x0000000000777cd5 in ha_innobase::rnd_pos(unsigned char*, unsigned char*) ()
#11 0x000000000069b637 in Rows_log_event::find_row(Relay_log_info const*) ()
#12 0x000000000069cd5f in Update_rows_log_event::do_exec_row(Relay_log_info const*) ()
#13 0x000000000069fc05 in Rows_log_event::do_apply_event(Relay_log_info const*) ()
#14 0x00000000005e76b7 in ?? ()
#15 0x00007f56139a8674 in ?? () from /usr/lib/galera/libmmgalera.so
#16 0x00007f56139a9678 in process_query_write_set_applying ()
   from /usr/lib/galera/libmmgalera.so
#17 0x00007f56139a9fd4 in ?? () from /usr/lib/galera/libmmgalera.so
#18 0x00007f56139abeeb in ?? () from /usr/lib/galera/libmmgalera.so
#19 0x00000000005e624c in wsrep_replication_process(THD*) ()

#0 pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1 0x00000000007e7345 in os_event_wait_low ()
#2 0x000000000081ec05 in sync_array_wait_event ()
#3 0x0000000000820292 in mutex_spin_wait ()
#4 0x0000000000809cee in row_search_check_if_query_cache_permitted ()
#5 0x000000000077f49a in ?? ()
#6 0x000000000070f494 in Query_cache::ask_handler_allowance(THD*, TABLE_LIST*) ()
#7 0x0000000000712e27 in Query_cache::store_query(THD*, TABLE_LIST*) ()
#8 0x00000000005e40d8 in ?? ()
#9 0x00000000005e9cec in mysql_execute_command(THD*) ()
#10 0x00000000005ef3d1 in mysql_parse(THD*, char const*, unsigned int, char const**) ()
#11 0x00000000005f0e5f in dispatch_command(enum_server_command, THD*, char*, unsigned int)
    ()
#12 0x00000000005f1b71 in do_command(THD*) ()
#13 0x00000000005e06fd in handle_one_connection ()
#14 0x00007f5619cf29ca in start_thread (arg=<value optimized out>) at pthread_create.c:300
#15 0x00007f56191766cd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#16 0x0000000000000000 in ?? ()

Changed in codership-mysql:
milestone: none → 0.7.4
Revision history for this message
Teemu Ollakka (teemu-ollakka) wrote :
Changed in codership-mysql:
status: Confirmed → Fix Committed
Changed in codership-mysql:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.