Bug #3859 All Inno DB tables on entire server locked up
Submitted: 22 May 2004 17:00 Modified: 30 Oct 2004 9:02
Reporter: Joseph Strano Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:4.0.18 OS:Linux (Red Hat Linux release 9 (Shrike))
Assigned to: Heikki Tuuri CPU Architecture:Any

[22 May 2004 17:00] Joseph Strano
Description:
During a restore of one DB, one of our techs decides to restart the MySQL server.  Knowing about the table lock issue, we figure that the one DB would be locked until we followed the procedures in 15.1.  However, ALL Inno DBs were locked on the ENTIRE SERVER.  When we tried to follow the steps in 15.1, we didn't see anything in the innodb_table_monitor that had a # in front.  

The only way we could drop this DB was to delete the directory in /var/lib/mysql

Now, luckily, there are no live DBs on this server that are using Inno.  So we re-created the issue this morning successfully.  I can re-create for you again if necessary any time you wish.

How to repeat:
Create at least 2 different users on the same server.  Ensure both have Inno tables.
Start a restore
Re-Start the MySQL server

You will notice that all Inno tables on that server are locked, and I was unable to find a way to un-lock them.

Suggested fix:
How about an automatic recovery to handle stuff like this?
[23 May 2004 16:39] Alexander Keremidarski
I was able to repeat the problem with latest 4.1 from BK tree (ChangeSet@1.1863, 2004-05-22 23:41:58+04:00), but *NOT* with latest 4.0 (ChangeSet@1.1842, 2004-05-20 13:54:52+03:00)

Test case which breaks for 4.1 :

CREATE TABLE bug3859 (id INT) Engine=InnoDB;
INSERT INTO bug3859 VALUES(1);
BEGIN;
SELECT * FROM bug3859 WHERE id = 1 FOR UPDATE;

# Restart mysqld
# After restart try:

SELECT * FROM bug3859;
ERROR 1016 (HY000): Can't open file: 'l1.InnoDB' (errno: 1)
[24 May 2004 9:24] Heikki Tuuri
Joseph,

do you mean that you were running some huge LOAD DATA INFILE when you decided to kill mysqld? At the mysqld restart, InnoDB will roll back the huge transaction before allowing user connections.

It is in the TODO to make the rollback in the background. There is really no need to keep the entire server inaccessible during the rollback at the mysqld start.

The innnodb_table_monitor only shows #sql... tables if you were running an ALTER TABLE. MySQL creates a temporary table #sql... when it does an ALTER TABLE.

I guess you were referring to this advice about how to stop a runaway rollback:
http://www.innodb.com/ibman.php#Forcing.recovery
"
Starting from version 3.23.53 and 4.0.4, you are allowed to DROP or CREATE a table even if forced recovery is used. If you know that a certain table is causing a crash in rollback, you can drop it. You can use this also to stop a runaway rollback caused by a failing mass import or ALTER TABLE. You can kill the mysqld process and use the my.cnf option innodb_force_recovery=3 to bring your database up without the rollback. Then DROP the table which is causing the runaway rollback.
"

About Alexander's observation in 4.1, I am now building the latest 4.1 to study it. Looks like the table did not get its entry into InnoDB's internal data dictionary.

Regards,

Heikki
[24 May 2004 13:40] Joseph Strano
To be completely honest, I am not sure how it happened the first time.  I do not believe there was any create scripts running at the time, however there might have been a data upload script running that created data only (no table modifications).

The 2nd time, one admin was performing a DB restore while another decided to restart the MySQL server.  

Both times, all Inno DB tables were completely locked, and remainded that way.  I couldn't drop them .. I couldn't even drop the DB they were in without deleting the directory in the MySQL directory structure.  We didn't try the innodb_force_recovery setting though, as I hadn't seen that one.  We were looking at 15.1, so I ran the monitor to look for #sql tables, and found none.

Now, just for clarification, after the DB comes back up with that force recovery setting, I would have to drop the table(s) that were causing the issue?  How can I recover those tables, other then copying them out of the backup file?

Thank you for this information so far.  Inno is a very serious step toward making MySQL a fully functional DB, and I applaud your efforts.
[24 May 2004 14:21] Heikki Tuuri
Hi!

If you were running a huge LOAD DATA INFILE, and decide to kill mysqld, then it will roll back the big transaction at the next startup, and that may take days. You can only use the DROP TABLE method described in section 6.1 of the InnoDB manual if you can restore the table from a backup.

Workaround: import smaller pieces of the infile at a time.

Feature request (TODO): add commits to LOAD DATA INFILE at every 10 000 rows. Check that this does not break MySQL's binlog replication.

Regards,

Heikki
[24 May 2004 14:37] Joseph Strano
Well, I'm not sure if you can consider this huge.  The DB they were restoring was 60 tables with about 5,000 records total.  I can understand why this DB would be locked up while the restore was occuring, but why would EVERY Inno DB on the server be locked for this time?
[24 May 2004 14:48] Heikki Tuuri
Hi!

If the tables were that small then I do not understand why you had problems. You should submit a repeatable test case for this bug.

Regards,

Heikki
[26 May 2004 23:55] Heikki Tuuri
Hi!

I was not able to repeat with the latest 4.1 the problem reported by Alexander. How did you restart mysqld? Are you sure the restarted mysqld had the same my.cnf? You can get that error if the restarted mysqld saw a different ibdata1 file.

About the restore + lock problem, can Joseph explain what he means by 'performing a restore'? Running some script? What is that script like? What does 'locked' mean? SHOW PROCESSLIST shows all queries in the 'locked' state?

Regards,

Heikki

Terminal 1:

heikki@hundin:~/mysql-4.1/sql> ./mysqld
040527  0:42:57  Warning: You have enabled the binary log, but you haven't set s
erver-id to a non-zero value: we force server id to 1; updates will be logged to
 the binary log, but connections from slaves will not be accepted.
InnoDB: Resetting space id's in the doublewrite buffer
040527  0:42:57  InnoDB: Started; log sequence number 0 45516
InnoDB: You are upgrading to an InnoDB version which allows multiple
InnoDB: tablespaces. Wait that purge and insert buffer merge run to
InnoDB: completion...
InnoDB: Full purge and insert buffer merge completed.
InnoDB: You have now successfully upgraded to the multiple tablespaces
InnoDB: format. You should NOT DOWNGRADE again to an earlier version of
InnoDB: InnoDB! But if you absolutely need to downgrade, see section 4.6 of
InnoDB: http://www.innodb.com/ibman.php for instructions.
040527  0:42:59  mysql.user table is not updated to new password format; Disabli
ng new password usage until mysql_fix_privilege_tables is run
./mysqld: ready for connections.
Version: '4.1.2-alpha-debug-log'  socket: '/home/heikki/bugsocket'  port: 3307
040527  0:44:20  Got signal 15 to shutdown mysqld
040527  0:44:20  ./mysqld: Normal shutdown

040527  0:44:21  InnoDB: Starting shutdown...
040527  0:44:23  InnoDB: Shutdown completed; log sequence number 0 47122
040527  0:44:24  ./mysqld: Shutdown Complete

heikki@hundin:~/mysql-4.1/sql> ./mysqld
040527  0:44:44  Warning: You have enabled the binary log, but you haven't set s
erver-id to a non-zero value: we force server id to 1; updates will be logged to
 the binary log, but connections from slaves will not be accepted.
040527  0:44:44  InnoDB: Started; log sequence number 0 47122
040527  0:44:45  mysql.user table is not updated to new password format; Disabli
ng new password usage until mysql_fix_privilege_tables is run
./mysqld: ready for connections.
Version: '4.1.2-alpha-debug-log'  socket: '/home/heikki/bugsocket'  port: 3307

Terminal 2:

heikki@hundin:~/mysql-4.1/client> ./mysql test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 4.1.2-alpha-debug-log

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

mysql> CREATE TABLE bug3859 (id INT) Engine=InnoDB;
Query OK, 0 rows affected (0.01 sec)

mysql> INSERT INTO bug3859 VALUES(1);
Query OK, 1 row affected (0.01 sec)

mysql> BEGIN;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM bug3859 WHERE id = 1 FOR UPDATE;
+------+
| id   |
+------+
|    1 |
+------+
1 row in set (0.00 sec)

mysql>
mysql> exit
Bye
heikki@hundin:~/mysql-4.1/client> ./mysql test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 4.1.2-alpha-debug-log

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

mysql> SELECT * FROM bug3859;
+------+
| id   |
+------+
|    1 |
+------+
1 row in set (0.01 sec)

mysql>

Terminal 3:

heikki@hundin:~/mysql-4.1/client> ./mysqladmin shutdown
heikki@hundin:~/mysql-4.1/client>
[27 May 2004 3:53] Joseph Strano
1.  I restarted MySQL through WHM (cPanel's server management software).  There were no changes to any configuration files.

2.  Every Inno DB table showed In Use in PhPMyAdmin.  When I tried to run a repair on the DB, I recived the following:

error    : Can't open file: 'FORM_COLUMN.InnoDB'. (errno: 1)
utility_beta.FORM_COLUMN_DATA
[27 May 2004 15:25] Heikki Tuuri
Joseph,

we need a test case that is repeatable withn just mysqld and the mysql command-line SQL client. I am not familiar with the frontend tools that you used.

The error message that you got means that the .frm file for the table exists, but the table does NOT exist inside ibdata files.

Regards,

Heikki
[27 May 2004 15:31] Joseph Strano
I do not know the command line commands for restarting the DB through WHM, but I can attempt to find out.  I just posted a message on cPanel's forums and will let you know if I receive an answer.
[27 May 2004 15:48] Joseph Strano
Ok, cPanel replied:

at the shell prompt as root:

service mysql restart

or

/etc/init.d/mysql restart