Debugging results #1

*****************************************************************************

• • Thread 4
    *****************************************************************************
    "ANALYZE TABLE A"

• Has a table lock on table A << How do we kow that??
  Tries to get three locks: { table_stat, column_stat, index_stat }, all for
  TL_WRITE..
  
  We're hung on getting the 3rd one.. it's a TL_WRITE lock on index_stat.
  
  #2 wait_for_lock (wait=0x7f868c038580, data=0x7f86800371a0, in_wait_list=0 '\000', lock_wait_timeout=<optimized out>) at /home/psergey/dev2/maria-5.5-mwl248/mysys/thr_lock.c:569
  (gdb) p data->lock->name
  $374 = 0x7f868c02a580 "index_stat"
  
  We are:
  (gdb) p thd->lock_info
  $405 = {thread = 140216257513216, thread_id = 25}
  
  We're waiting on: index_stat,:
  
  (gdb) p * data->lock->read->data->owner
  $415 = {thread = 140216257214208, thread_id = 26}
  
  *****************************************************************************
  ** Thread 3
  *****************************************************************************
  "SELECT * FROM mysql.index_stat, test.E LIMIT 1"
  
  #3 in thr_lock ()
  #4 thr_multi_lock ()
  #5 in mysql_lock_tables ()
  #6 in mysql_lock_tables ()
  #7 in lock_tables ()
  #8 in open_and_lock_tables ()
  #9 in open_and_lock_tables ()
  #10 open_system_tables_for_read ()
  #11 in read_statistics_for_tables_if_needed ()
  
  Here:
  lock_count=3, { table_stat, column_stat, index_stat }

  
  type=TL_READ on every one.

We're stuck when locking table #0, table_stat.
#2 wait_for_lock (wait=0x7f868c02d620, data=0x7f868002d510, in_wait_list=0 '\000', lock_wait_timeout=<optimized out>) at /home/psergey/dev2/maria-5.5-mwl248/mysys/thr_lock.c:569
(gdb) p data->lock->name
$376 = 0x7f868c02a510 "table_stat"

We are:
(gdb) p thd->lock_info
$421 =

We're waiting on: table_stat, READ lock.

(gdb) p * data->lock->write->data->owner
$435 =

Ok, we're thread 24 and we're waiting for "table_stat" because thread 25 has it.

A hypothesis:

Deadlock is caused by this sequence of events:

SELECT takes a read lock on

ANALYZE TABLE A tries to take write locks on

it gets locks on table_stat and column_stat
it doesn't get lock on index_stat, because it is locked.
It ends up waiting.

SELECT tries to load statistics data for the tables it is using.
table_stat is locked by the ANALYZE command, so it is waiting.

(The other ANALYZE command is also waiting, but it not actually pariticipating
in the deadlock. Perhaps, it is necessary so that SELECT will try to load
statistics data)

Info requested by Igor: I observed the problem on maria-5.5-mwl248 revno 3569 (and AFAIR also double-checked later on 3570).

The bug was fixed in maria-5.5-mwl248 by the following revision:

revno: 3577

revision-id: igor@askmonty.org-20121213071654-k1ghi7u5s10nvnno

parent: igor@askmonty.org-20121210053308-o0qpwt4upw7e9740

committer: Igor Babaev <igor@askmonty.org>

branch nick: maria-5.5-mwl248

timestamp: Wed 2012-12-12 23:16:54 -0800

message:

  Fixed bug mdev-3891.

  If a query referenced some system statistical tables, but not all of them,

  then executing an ANALYZE command simultaneously with this query could

  lead to a deadlock.

  The fix prohibited reading statistics from system statistical tables

  for such queries.

  Removed the function unlock_tables_n_open_system_tables_for_write()

  as not used anymore.

  Performed some minor refactoring of the code in sql_statistics.cc.