MySQL Bugs: #5714: Insert into MyISAM table and select ... for update

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

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?

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.

MySQL trace

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

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.

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

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

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