Bug #33191 Threads 'serialize' when multy-query delete trans. w/trig are run againt Falcon
Submitted: 13 Dec 2007 1:21 Modified: 2 May 2008 23:30
Reporter: Omer Barnir (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version:6.0.4 OS:Any
Assigned to: Kevin Lewis CPU Architecture:Any

[13 Dec 2007 1:21] Omer Barnir
Description:
As a background for this bug please see bug#33072.

When running concurrent delete operations against a falcon table where the delete action includes activating triggers on other tables and the operations are done as part of a single transaction, all threads running concurrently appear to be running in a very slow serialized  manner where one thread is 'updating' the table and all other are 'locked'.

Test Details:
 - A SP is run as a single transaction and performs the following
   = Inserts rows to table_a
   = Deletes rows on table_a
   = Table_a has a 'before delete' trigger that inserts a row to table_b

Running ten concurrent connections each executing the above, demostrates the problem clearly if checking from another client with show processlist':

a 'batch of ten threads 'cycles' for up to 120 seconds and then they are all completed. This is observed when the system is run with falcon_lock_timeout=50.
If running with the default falcon_lock_timeout=0 a deadlock is observed as described in bug #33072.

As a comparison, if running with innodb table, the threads 'cycle' in less ten a second (every run of 'show processlist' hows different threads and they all show a status of 'updating'.

Also note, the problem is not observed if:
 - running with autocommit=0
 - running with innodb (as mentioned above)
 - running without the triggers that insert rows to the other tables

How to repeat:
In order to reproduce the above you will need to be set with two ssh connections to the
test machine.

1) Download the attached files. Place the *.txt files in the mysql-test-directory 
   and the *.test files in the mysql-test/t directory.

2) From connection '1' (mysql-test directory)run the following command:
   perl ./mysql-test-run.pl --stress --stress-init-file=del_lock_init.txt 
                            --stress-test-file=del_lock_run.txt
                            --stress-test-duration=120 --stress-threads=10
>>> Once the server starts you will see lines in the form of 
    test_loop[0:0 0:154]: TID 5 test: 'del_lock_run'  
    Errors: No Errors. Test Passed OK

3) From connection '2' start a mysql client and repeatedly run 
   the 'show proceeslist' command.

Suggested fix:
Threads should not appear to be run in a serialized manner and should behave in a manner similar to innodb.
[13 Dec 2007 1:23] Omer Barnir
For test case, see files attached to bug#33072 at entry [7 Dec 20:35] Omer BarNir
[23 Dec 2007 8:22] Philip Stoev
If one issues a SELECT in a separate connection, it takes several minutes to complete (CPU usage being zero all the time).
[23 Dec 2007 18:07] Philip Stoev
Some relevant comments from the parent bug:

* As Omer observed, statements become serialized, running at 1 statement each
falcon_lock_timeout milliseconds. The stored procedure in question runs 100 such
statements and completes in 100 * falcon_lock_timeout * number_of_threads (50) msec. No
CPU activity takes place during the falcon_lock_timeout period.

* SELECT statements on the same table started in a separate connection take anywhere from
10 seconds to 2 minutes to run. It appears to me this means both that they are affected by
the timeout (was 10 seconds at the time of observation), that writes block reads and that
writes starve reads (cpu usage is very low all the time).

SELECTS are masssively delayed during the deadlock:

mysql> select * from test.tbl_a;
...
738 rows in set (13 min 13.45 sec)
[28 Dec 2007 5:59] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/40446

ChangeSet@1.2766, 2007-12-27 23:58:44-06:00, klewis@klewis-mysql. +1 -0
  Bug#33191 - Serialization of delete operations where trigers are involved 
  occured in the MySQL server.  StorageInterface::store_lock() was not 
  changing the lock_type to TL_WRITE_ALLOW_WRITE because the conditional 
  statement was incorrect.  This lower lock type allows multiple threads
  to do triggered deletes in Falcon concurrently.
  The condition is now like InnoDB except for allowing concurrent truncates,
  which Falcon can do.
[28 Dec 2007 6:08] Kevin Lewis
This test is designed to create deadlocks.  When the stored procedure is run against InnoDB with 2 or more clients concurrently, InnoDB recognizes deadlocks and automatically does a rollback on the transaction where it is detected.

Falcon however, cannot detect the deadlock because the threads representing the other transactions are being serialized in the MySQL server.  This happens in sql_delete.cc, mysql_delete() when it calls open_and_lock_tables().  The lock type used for Falcon is TL_WRITE. So even though there are multiple threads using Falcon during this test, they are mostly being serialized, at least for the deletes.  This is why Falcon can not detect the deadlock.  There is never more than one thread involved in this deadlock waiting in Falcon.  

InnoDB can detect the deadlock because the lock_type has been reduced to TL_WRITE_ALLOW_WRITE.  This is done in a handler function called ha_innobase::store_lock().  Falcon also has one of these handler functions; StorageInterface::store_lock().  In fact, Falcon attempts to lower the priority to TL_WRITE_ALLOW_WRITE also, but with conditions different than InnoDB.

If the same conditions are used in Falcon as what is used in InnoDB, then the Stored Procedure in this test can run concurrently within Falcon, the lock type is set to TL_WRITE_ALLOW_WRITE, and unlike InnoDB, there are no deadlocks detected.  And most importantly, the performance drop seems to go away.
[11 Feb 2008 20:40] Kevin Lewis
Patch is in mysql-6.0-falcon-team and mysql-6.0-release version 6.0.4
[12 Mar 2008 23:02] Bugs System
Pushed into 6.0.4-alpha
[2 May 2008 23:30] Paul DuBois
Note in 6.0.4 changelog.

Multiple concurrent delete operations on a Falcon table were
serialized rather than executing concurrently, resulting in poor
performance.