MySQL Bugs: #25642: Shutdown blocks until Falcon serial log is flushed to the Falcon datafile

Bug #25642	Shutdown blocks until Falcon serial log is flushed to the Falcon datafile
Submitted:	16 Jan 2007 3:03	Modified:	26 May 2010 17:48
Reporter:	Mark Callaghan	Email Updates:
Status:	Unsupported	Impact on me:	None
Category:	MySQL Server: Falcon storage engine	Severity:	S4 (Feature request)
Version:	5.1.14 Falcon	OS:	Linux (Linux 2.4)
Assigned to:		CPU Architecture:	Any
Tags:	Drop, F_SHUTDOWN, falcon, qc, slow

Description:
I created a table, inserted 10M rows, created a primary key index, waited a couple of minutes and then dropped the table. It took 3 minutes for the drop to return.

show processlist output during the drop
+----+------+-----------+------+---------+------+-----------------+------------------+
| Id | User | Host      | db   | Command | Time | State           | Info             |
+----+------+-----------+------+---------+------+-----------------+------------------+
|  5 | root | localhost | test | Query   |   28 | Waiting on cond | drop table C     |
|  6 | root | localhost | NULL | Query   |    0 | NULL            | show processlist |
+----+------+-----------+------+---------+------+-----------------+------------------+

How to repeat:
CREATE TABLE C (
  ChId bigint(20) NOT NULL default '0',
  Timestamp datetime NOT NULL default '0000-00-00 00:00:00',
  CuId int(11) NOT NULL default '0',
  CaId int(11) NOT NULL default '0',
  AId int(11) NOT NULL default '0',
  UId int(11) NOT NULL default '0',
  IpAddress varchar(15) NOT NULL default ''
) engine=Falcon;

insert 10M rows
alter table C add primary key (ChId);
wait several minutes
drop table C --> this takes 3 minutes to finish

Does Falcon block until all changes have been flushed from the serial log?

Thank you for the bug report. I was unable to repeat with source server
running on Dell 4700 512MB RAM:

mysql> select version();
+--------------------------+
| version()                |
+--------------------------+
| 5.2.1-falcon-alpha-debug | 
+--------------------------+
1 row in set (0.00 sec)

mysql> select count(*) from C;
+----------+
| count(*) |
+----------+
| 10004304 | 
+----------+
1 row in set (2 min 6.62 sec)

mysql> drop table C;?
Query OK, 0 rows affected (1.05 sec)

mysql> show tables;
Empty set (0.25 sec)

mysql> 

Which hardware and release package (source build) are you using?
Thanks in advance.

mysql> select version();
+---------------------+
| version()           |
+---------------------+
| 5.1.14-falcon-alpha |
+---------------------+

Did you try to drop the table soon after doing the insert? If there is enough time between completion of the insert and the drop, the drop is fast. I suspect that the drop is blocked on flushing of the changes from the Falcon serial log into the Falcon database file.

Thank you for the feedback. Indeed I did after a reasonable time after
the inserts. I will try again how you mentioned.

I just downloaded, built and installed 5.2. The problem does not reproduce there.

I now reproduce the problem with:
1) delete falcon files
2) start database
3) create table
4) insert 10M rows
5) quit
6) shutdown

The shutdown now takes several minutes and doesn't complete until the falcon serial log is flushed to the falcon datafile. That is, the problem occurs when I don't drop the table before shutdown.

Thank you for the feedback.

miguel@light:~/dbs/5.1f$ bin/mysql -uroot
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.2.4-falcon-alpha-debug Source distribution

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

mysql> create database db1;
Query OK, 1 row affected (0.03 sec)

mysql> use db1
Database changed
mysql> CREATE TABLE C (
    ->   ChId bigint(20) NOT NULL default '0',
    ->   Timestamp datetime NOT NULL default '0000-00-00 00:00:00',
    ->   CuId int(11) NOT NULL default '0',
    ->   CaId int(11) NOT NULL default '0',
    ->   AId int(11) NOT NULL default '0',
    ->   UId int(11) NOT NULL default '0',
    ->   IpAddress varchar(15) NOT NULL default ''
    -> ) engine=Falcon;
Query OK, 0 rows affected (0.28 sec)

mysql> load data infile '/home/miguel/falcon.sql' into table C  fields terminated by ',';
Query OK, 10000000 rows affected (10 hours 59 min 11.00 sec)
Records: 10000000  Deleted: 0  Skipped: 0  Warnings: 0

mysql> quit
Bye
miguel@light:~/dbs/5.1f$ 

miguel@light:~/dbs/5.1f$ bin/mysqladmin -uroot shutdown

Mark,

you described the steps of this like:
<quote>
I now reproduce the problem with:
1) delete falcon files
2) start database
3) create table
4) insert 10M rows
5) quit
6) shutdown
</quote>

A shutdown closes mysqld in a safe manner. This means that the shutdown waits on pending actions. I would say, that this is expected behavior.

Best regards,

Hakan

Blocking until the serial log is flushed is not required for safety. If that were the case, then Falcon does not provide durable transactions. The current behavior is very inconvient for scripts -- when tens or hundreds of servers are controlled by scripts, having a step take 10+ minutes is no fun. It will also break some scripts. Until recently, /etc/init.d/mysql had a 30 second timeout. With Falcon's current behavior and the old behavior of /etc/init.d/mysql (changed because of a bug I filed), /etc/init.d/mysql restart would timeout waiting for the shutdown, and then start a second mysqld instance.

InnoDB has an option to do fast shutdown. If nothing else is provided, Falcon should have a similar option.

Mark,

you have perfectly valid points. I changed this bug report to feature request. Falcon should have a "fast shutdown" switch.

Best regards,

Hakan