Bug #5714 Insert into MyISAM table and select ... for update
Submitted: 23 Sep 2004 9:34 Modified: 8 Nov 2004 9:04
Reporter: Igor Blagodetelev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:4.0.21 OS:Linux (Linux RHEL AS 3.0)
Assigned to: Guilhem Bichot CPU Architecture:Any

[23 Sep 2004 9:34] Igor Blagodetelev
Description:
"select * from innodb_table for update" - lock released if "insert into myisam_table values ()" statement called.

How to repeat:
Connection "A":
[lion@develop lion]$ mysql -uroot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 355 to server version: 4.0.21-Max-log

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> drop table if exists m; drop table if exists i; select version(); create table m (id int) type=MyISAM; create table i (id int) type=InnoDB; insert into i values (1); begin; select * from i for update;
Query OK, 0 rows affected (0.00 sec)

Query OK, 0 rows affected (0.01 sec)

+----------------+
| version()      |
+----------------+
| 4.0.21-Max-log |
+----------------+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

Query OK, 0 rows affected (0.07 sec)

Query OK, 1 row affected (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

+------+
| id   |
+------+
|    1 |
+------+
1 row in set (0.00 sec)

Connection "B":
mysql> begin; select * from i for update;
Query OK, 0 rows affected (0.00 sec)
---- Wait for lock released ----

Connection "A":
mysql> insert into m values (20);
Query OK, 1 row affected (0.00 sec)

Connection "B":
+------+
| id   |
+------+
|    1 |
+------+
1 row in set (3.67 sec)

Why lock released too early?
[8 Oct 2004 13:08] Michael Widenius
Hi!

I did a test for this both with the newest 4.0 tree and 4.1 tree and your test case worked with both.

In both cases, I got for connection B:

ERROR 1205: Lock wait timeout exceeded; try restarting transaction

If I did a commit on 'A' then 'B was released

Could you try to use a mysqld server compiled with debugging and run mysqld with --debug and then try to repeat this ?
If this succeeds, then the trace file in /tmp/mysqld.trace should contain enough information for us to find the problem.
[11 Oct 2004 5:48] Igor Blagodetelev
MySQL trace

Attachment: mysqld.trace.gz (application/x-gunzip, text), 31.31 KiB.

[11 Oct 2004 5:53] Igor Blagodetelev
Ok, I have rebuilded MySQL with --debug, enable debug trace and I have repeated the test how I wrote before. The trace file was gzipped and attached to this bug.
[22 Oct 2004 7:44] Heikki Tuuri
Hi!

I am able to repeat this with the latest 4.0.22 tree with the binlog enabled. I am also able to repeat this with 4.0.18-standard.

The bug is in the following reasoning by me:

log.cc:
"
    /*
      Tell for transactional table handlers up to which position in the
      binlog file we wrote. The table handler can store this info, and
      after crash recovery print for the user the offset of the last
      transactions which were recovered. Actually, we must also call
      the table handler commit here, protected by the LOCK_log mutex,
      because otherwise the transactions may end up in a different order
      in the table handler log!

      Note that we will NOT call ha_report_binlog_offset_and_commit() if
      there are binlog events cached in the transaction cache. That is
      because then the log event which we write to the binlog here is
      not a transactional event. In versions < 4.0.13 before this fix this
      caused an InnoDB transaction to be committed if in the middle there
      was a MyISAM event!
    */

    if (file == &log_file) // we are writing to the real log (disk)
    {
      if (flush_io_cache(file))
        goto err;

      if (opt_using_transactions && !my_b_tell(&thd->transaction.trans_log))
      {
        /*
          LOAD DATA INFILE in AUTOCOMMIT=1 mode writes to the binlog
          chunks also before it is successfully completed. We only report
          the binlog write and do the commit inside the transactional table
          handler if the log event type is appropriate.
        */

        if (event_info->get_type_code() == QUERY_EVENT ||
            event_info->get_type_code() == EXEC_LOAD_EVENT)
        {
          error = ha_report_binlog_offset_and_commit(thd, log_file_name,
                                                     file->pos_in_file);
          called_handler_commit=1;
        }
      }
"

In this case, connection A has a row lock inside InnoDB, but the transaction.translog for the transaction is still empty! That causes the call of ha_report_binlog_offset_and_commit().

Possible fix:

1) Find a correct way to differentiate between binlog events that are COMMITs, and events that are just writes to the binlog.

Or:

2) Let InnoDB do the commit in ha_report_binlog_offset_and_commit() only if trx->undo_no in InnoDB is > 0.

Regards,

Heikki
[22 Oct 2004 7:53] Heikki Tuuri
Guilhem,

is there a way to differentiate between binlog writes due to a transaction commit (or an autocommit of an SQL statement), and other binlog writes?

Regards,

Heikki
[8 Nov 2004 9:04] Guilhem Bichot
Thank you for your bug report. This issue has been committed to our
source repository of that product and will be incorporated into the
next release.

If necessary, you can access the source repository and build the latest
available version, including the bugfix, yourself. More information 
about accessing the source trees is available at
    http://www.mysql.com/doc/en/Installing_source_tree.html

Additional info:

ChangeSet@1.2055.4.1, 2004-11-04 19:19:23+01:00, guilhem@mysql.com