Bug #42147 Concurrent DML and LOCK TABLE ... READ for InnoDB table cause warnings in errlog
Submitted: 16 Jan 2009 6:06 Modified: 19 Jun 2014 22:23
Reporter: Dmitry Lenev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Locking Severity:S3 (Non-critical)
Version:5.0.77-bzr, 5.1, 6.0 OS:Any
Assigned to: Jon Olav Hauglid CPU Architecture:Any
Triage: Triaged: D3 (Medium)

[16 Jan 2009 6:06] Dmitry Lenev
Description:
For debug version of server concurrent execution of LOCK TABLES ... READ and DML statement modifying the same InnoDB table (e.g. INSERT) might result in warnings about wrong locking in error log.

Unlike bugs #41688 and #42069 which have similar symptoms this bug can't be fixed by changes in storage engine alone.

OTOH I suspect that wrong behavior of our locking subsystem exposed by these warnings can't do any real harm as InnoDB also relies on its own locking.

How to repeat:
# Run the following script for mysqltest tool for server built with InnoDB support # and in debug mode.

--source include/have_innodb.inc

connect (addcon, localhost, root,,);
connection default;
create table t1 (i int) engine= innodb;
# Use sleep() function to simulate certain scheduling()
--send insert into t1 values (sleep(5));
connection addcon;
--sleep 2
lock tables t1 read;
unlock tables;
connection default;
--reap

# Inspect server's error log (master.err) afterwards and see
#Warning at 'read lock with old write lock': Found lock of type 5 that is write and read locked
#Warning at 'start of release lock': Found lock of type 5 that is write and read locked

Suggested fix:
Fix code in thr_lock.c which grants TL_READ_NO_INSERT locks if there are other threads holding TL_WRITE_ALLOW_WRITE lock on the table.
[16 Jan 2009 7:14] Valeriy Kravchuk
Thank you for a bug report. Verified just as described:

openxs@suse:/home2/openxs/dbs/5.0/mysql-test> ./mysql-test-run.pl 42147
Logging: ./mysql-test-run.pl 42147
MySQL Version 5.0.76
Using ndbcluster when necessary, mysqld supports it
Setting mysqld to support SSL connections
Binaries are debug compiled
mysql-test-run: WARNING: Could not find all required ndb binaries, all ndb tests will fail, use --skip-ndbcluster to skip testing it.
Using MTR_BUILD_THREAD      = 0
Using MASTER_MYPORT         = 9306
Using MASTER_MYPORT1        = 9307
Using SLAVE_MYPORT          = 9308
Using SLAVE_MYPORT1         = 9309
Using SLAVE_MYPORT2         = 9310
Using NDBCLUSTER_PORT       = 9311
Using IM_PORT               = 9313
Using IM_MYSQLD1_PORT       = 9314
Using IM_MYSQLD2_PORT       = 9315
Killing Possible Leftover Processes
Removing Stale Files
Creating Directories
Installing Master Database
=======================================================
Starting Tests in the 'main' suite

TEST                           RESULT         TIME (ms)
-------------------------------------------------------

42147                          [ fail ]

mysqltest: The specified result file does not exist: '/home2/openxs/dbs/5.0/mysql-test/r/42147.result'

The result from queries just before the failure was:
create table t1 (i int) engine= innodb;
insert into t1 values (sleep(5));;
lock tables t1 read;
unlock tables;

More results from queries before failure can be found in /home2/openxs/dbs/5.0/mysql-test/var/log/42147.log

Aborting: 42147 failed in default mode.
To continue, re-run with '--force'.
Stopping All Servers
skipped 9 bytes from file: socket (3)
openxs@suse:/home2/openxs/dbs/5.0/mysql-test> tail var/log/master.err
Version: '5.0.76-debug-log'  socket: '/home2/openxs/dbs/5.0/mysql-test/var/tmp/master.sock'  port: 9306  Source distribution
Warning at 'read lock with old write lock': Found lock of type 5 that is write and read locked
Warning at 'start of release lock': Found lock of type 5 that is write and read locked
081220 12:05:02 [Note] Got signal 15 to shutdown mysqld
081220 12:05:02 [Note] /home2/openxs/dbs/5.0/libexec/mysqld: Normal shutdown

081220 12:05:02  InnoDB: Starting shutdown...
081220 12:05:04  InnoDB: Shutdown completed; log sequence number 0 45505
081220 12:05:04 [Note] /home2/openxs/dbs/5.0/libexec/mysqld: Shutdown complete
[16 Jan 2009 7:17] Valeriy Kravchuk
Similar warning (other lock type, though) on recent 6.0.10 from bzr:

081220 12:08:19  InnoDB: Started; log sequence number 0 0
081220 12:08:20 [Note] Event Scheduler: Loaded 0 events
081220 12:08:20 [Note] /home2/openxs/dbs/6.0/libexec/mysqld: ready for connections.
Version: '6.0.10-alpha-debug-log'  socket: '/home2/openxs/dbs/6.0/mysql-test/var/tmp/master.sock'  port: 9306  Source distribution
Warning at 'read lock with old write lock': Found lock of type 6 that is write and read locked
Warning at 'start of release lock': Found lock of type 6 that is write and read locked
081220 12:08:26 [Note] Got signal 15 to shutdown mysqld
081220 12:08:26 [Note] /home2/openxs/dbs/6.0/libexec/mysqld: Normal shutdown

081220 12:08:26 [Note] Event Scheduler: Purging the queue. 0 events
081220 12:08:26  InnoDB: Starting shutdown...
081220 12:08:28  InnoDB: Shutdown completed; log sequence number 0 48015
081220 12:08:29 [Note] Debug sync points hit:                   21
081220 12:08:29 [Note] Debug sync points executed:              0
081220 12:08:29 [Note] Debug sync points max active per thread: 0
081220 12:08:29 [Note] /home2/openxs/dbs/6.0/libexec/mysqld: Shutdown complete
[9 Jul 2009 9:23] Konstantin Osipov
Also causing sporadic foreign_key_all_engines test failures in the foreign keys feature tree.
[23 Jul 2009 12:35] 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/79182

2828 Jon Olav Hauglid	2009-07-23
      Bug #42147 Concurrent DML and LOCK TABLE ... READ for InnoDB 
                 table cause warnings in errlog
      
      Table lock compatibility matrix updated to disallow TL_READ_NO_INSERT 
      if another connection holds TL_WRITE_ALLOW_WRITE. Code comment updated 
      to match implemented behaviour (it didn't before).
      
      Test case added to innodb_mysql_lock.test.
[19 Aug 2009 11:24] 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/81060

2866 Jon Olav Hauglid	2009-08-19
      Bug #42147 Concurrent DML and LOCK TABLE ... READ for InnoDB 
                 table cause warnings in errlog
            
      Table lock compatibility matrix updated to disallow TL_READ_NO_INSERT 
      if another connection holds TL_WRITE_ALLOW_WRITE. Code comment updated 
      to match implemented behaviour (it didn't before).
      
      Test case added to innodb_mysql_lock.test.
[25 Aug 2009 8:41] 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/81478

2877 Jon Olav Hauglid	2009-08-25
      Bug #42147 Concurrent DML and LOCK TABLE ... READ for InnoDB 
                 table cause warnings in errlog
            
      The table lock compatibility matrix cannnot be updated to allow
      TL_READ_NO_INSERT when another connection holds TL_WRITE_ALLOW_WRITE
      without causing starvation of LOCK TABLE READ in InnoDB under
      high write load. This patch therefore contains no code changes.
      
      The issue will be fixed later when LOCK TABLE READ has been updated
      to not use table locks. This bug will therefore be marked as 
      "To be fixed later".
      
      Code comment in thr_lock.c expanded to clarify the issue and a 
      test case based on the bug description added to innodb_mysql_lock.test.
      Note that this test case for now suppresses the warnings generated by InnoDB.
[9 Sep 2009 10:42] 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/82801

2813 Jon Olav Hauglid	2009-09-09
      Bug #42147 Concurrent DML and LOCK TABLE ... READ for InnoDB 
                 table cause warnings in errlog
      
      Concurrent execution of LOCK TABLES ... READ statement and DML statements 
      affecting the same InnoDB table on debug builds of MySQL server might lead 
      to "Found lock of type 6 that is write and read locked" warnings appearing 
      in error log.
      
      The problem is that the table-level locking code allows a thread to acquire
      TL_READ_NO_INSERT lock on a table even if there is another thread which holds 
      TL_WRITE_ALLOW_WRITE lock on the same table. At the same time, the locking
      code assumes that that such locks are incompatible (for example, see check_locks()).
      
      This doesn't lead to any problems other than warnings in error log for
      debug builds of server since for InnoDB tables TL_READ_NO_INSERT type of
      lock is only used for LOCK TABLES and for this statement InnoDB also
      performs its own table-level locking.
      
      Unfortunately, the table lock compatibility matrix cannnot be updated to allow
      TL_READ_NO_INSERT when another thread holds TL_WRITE_ALLOW_WRITE without 
      causing starvation of LOCK TABLE READ in InnoDB under high write load. 
      This patch therefore contains no code changes.
      
      The issue will be fixed later when LOCK TABLE READ has been updated
      to not use table locks. This bug will therefore be marked as 
      "To be fixed later".
      
      Code comment in thr_lock.c expanded to clarify the issue and a 
      test case based on the bug description added to innodb_mysql_lock.test.
      Note that a global suppression rule has been added for the 
      "Found lock of type 6 that is write and read locked" warning.
[9 Sep 2009 13:09] 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/82819

2813 Jon Olav Hauglid	2009-09-09
      Bug #42147 Concurrent DML and LOCK TABLE ... READ for InnoDB 
                 table cause warnings in errlog
      
      Concurrent execution of LOCK TABLES ... READ statement and DML statements 
      affecting the same InnoDB table on debug builds of MySQL server might lead 
      to "Found lock of type 6 that is write and read locked" warnings appearing 
      in error log.
      
      The problem is that the table-level locking code allows a thread to acquire
      TL_READ_NO_INSERT lock on a table even if there is another thread which holds 
      TL_WRITE_ALLOW_WRITE lock on the same table. At the same time, the locking
      code assumes that that such locks are incompatible (for example, see check_locks()).
      
      This doesn't lead to any problems other than warnings in error log for
      debug builds of server since for InnoDB tables TL_READ_NO_INSERT type of
      lock is only used for LOCK TABLES and for this statement InnoDB also
      performs its own table-level locking.
      
      Unfortunately, the table lock compatibility matrix cannot be updated to disallow
      TL_READ_NO_INSERT when another thread holds TL_WRITE_ALLOW_WRITE without 
      causing starvation of LOCK TABLE READ in InnoDB under high write load. 
      This patch therefore contains no code changes.
      
      The issue will be fixed later when LOCK TABLE READ has been updated
      to not use table locks. This bug will therefore be marked as 
      "To be fixed later".
      
      Code comment in thr_lock.c expanded to clarify the issue and a 
      test case based on the bug description added to innodb_mysql_lock.test.
      Note that a global suppression rule has been added to both MTR v1 and v2
      for the "Found lock of type 6 that is write and read locked" warning.
      These suppression rules must be removed once this bug fix properly fixed.
[9 Sep 2009 13:19] Jon Olav Hauglid
Pushed to mysql-next-bugfixing (5.4.4-alpha)
[15 Sep 2009 13:52] Bugs System
Pushed into 5.4.4-alpha (revid:alik@sun.com-20090915134838-5nj3ycjfsqc2vr2f) (version source revid:jon.hauglid@sun.com-20090909130125-kq79wf5kjyav900i) (merge vers: 5.4.4-alpha) (pib:11)
[16 Sep 2009 11:36] Jon Olav Hauglid
Setting this bug as "To be fixed later" as instructed by Kostja.
(The pushed patch contains no code changes)
[9 Dec 2009 15:13] Jon Olav Hauglid
Pushed to mysql-next-4284 (5.6.0-beta).
[16 Feb 2010 16:49] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100216101445-2ofzkh48aq2e0e8o) (version source revid:kostja@sun.com-20091211154405-c9yhiewr9o5d20rq) (merge vers: 6.0.14-alpha) (pib:16)
[16 Feb 2010 16:58] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100216101208-33qkfwdr0tep3pf2) (version source revid:kostja@sun.com-20091210084103-l4f8u62u4evoy3dc) (pib:16)
[2 Mar 2010 1:08] Paul Dubois
Noted in 6.0.14 changelog.

Concurrent execution of a LOCK TABLES ... READ statement and DML
statements affecting the same InnoDB table for debug builds of MySQL
server might lead to "Found lock of type 6 that is write and read
locked" warnings in the error log. 

Setting report to Need Merge pending push of Celosia to release tree.
[6 Mar 2010 11:07] Bugs System
Pushed into 5.5.3-m3 (revid:alik@sun.com-20100306103849-hha31z2enhh7jwt3) (version source revid:vvaintroub@mysql.com-20100216221947-luyhph0txl2c5tc8) (merge vers: 5.5.99-m3) (pib:16)
[7 Mar 2010 12:56] Paul Dubois
Noted in 5.5.3 changelog.
[12 Apr 2010 8:23] Jon Stephens
Per developer comments above and DLenev mail to Docs Team: 

No fix was ever pushed for this bug.

Commented out changelog entry. Bug status unchanged.
[19 Jun 2014 22:23] Paul Dubois
Noted in 5.7.5 changelog.

For debug builds, concurrent execution of LOCK TABLES ... READ and a
DML statement affecting the same InnoDB table might lead to "Found
lock of type 6 that is write and read locked" warnings in the error
log.