Bug #45541 OPTIMIZE + server shutdown may damage a MyISAM table (due to thread kill)

Submitted: 17 Jun 2009 0:29 Modified: 17 Jun 2009 7:51
Reporter: Roel Van de Paar Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: MyISAM storage engine Severity:S1 (Critical)
Version:5.0.68, 5.1 OS:Any (MS Windows, Mac OS X, all)
Assigned to: CPU Architecture:Any

[17 Jun 2009 0:29] Roel Van de Paar
Description:
Issue seen:

[Changes made to log for privacy purposes: xx instead of day/time, 'Customer' instead of 2 customer name subdirs, 'table' and 'TaBle' instead of actual table name, though likely not important - notice the case difference,'database' instead of actual database name]

---------
0905xx xx:xx:xx InnoDB: Started; log sequence number 0 1330352629
0905xx xx:xx:xx [Note] C:\Program Files\Customer\server\mysql\bin\mysqld-nt.exe: ready for connections.
Version: '5.0.68-enterprise-nt-log' socket: '' port: 3908 MySQL Enterprise Server (Commercial)
0905xx xx:xx:xx [Note] C:\Program Files\Customer\server\mysql\bin\mysqld-nt.exe: Normal shutdown

0905xx xx:xx:xx [Warning] C:\Program Files\Customer\server\mysql\bin\mysqld-nt.exe: Forcing close of thread 6 user: 'Administrator'

0905xx xx:xx:xx [Warning] C:\Program Files\Customer\server\mysql\bin\mysqld-nt.exe: Forcing close of thread 5 user: 'Administrator'

0905xx xx:xx:xx [Warning] Warning: Optimize table got errno 120 on database.TaBle, retrying
0905xx xx:xx:xx [Note] Retrying repair of: './database/table' failed. Please try REPAIR EXTENDED or myisamchk
0905xx xx:xx:xx InnoDB: Starting shutdown...
0905xx xx:xx:xx InnoDB: Shutdown completed; log sequence number 0 1330355282
0905xx xx:xx:xx [Note] C:\Program Files\Customer\server\mysql\bin\mysqld-nt.exe: Shutdown complete

0905xx xx:xx:xx InnoDB: Started; log sequence number 0 1330355282
0905xx xx:xx:xx [Note] C:\Program Files\Customer\server\mysql\bin\mysqld-nt.exe: ready for connections.
Version: '5.0.68-enterprise-nt-log' socket: '' port: 3908 MySQL Enterprise Server (Commercial)
0905xx xx:xx:xx [ERROR] C:\Program Files\Customer\server\mysql\bin\mysqld-nt.exe: Table '.\database\table' is marked as crashed and last (automatic?) repair
failed
0905xx xx:xx:xx [ERROR] C:\Program Files\Customer\server\mysql\bin\mysqld-nt.exe: Table '.\database\table' is marked as crashed and last (automatic?) repair
failed
---------

Note the 120 error:
0905xx xx:xx:xx [Warning] Warning: Optimize table got errno 120 on database.TaBle, retrying

perror 120:
MySQL error code 120: Didn't find key on read or update
Win32 error code 120: This function is not supported on this system.

o Table was *not* defined with DELAY_KEY_WRITE (see bug #41330) 
o Customer is using myisam-recover=BACKUP,FORCE in my.ini
o No antivirus software

How to repeat:
Unknown, happened twice now.

Suggested fix:
Unknown
[17 Jun 2009 0:47] Roel Van de Paar
Besides reviewing bug #41330 (even though it seems not related, as per the above), also note bug's #8067, #10767 (especially the last remark), and #25433.
[17 Jun 2009 5:32] Roel Van de Paar
Researching some related bugs brought up some interesting information:

'Killing a REPAIR TABLE or OPTIMIZE TABLE operation on a MyISAM table results in a table that is corrupted and unusable. Any reads or writes to such a table fail until you optimize or repair it again (without interruption).'
http://dev.mysql.com/doc/refman/5.0/en/kill.html

And:

'Some threads might refuse to be killed. For example, REPAIR TABLE, CHECK TABLE, and OPTIMIZE TABLE cannot be killed before MySQL 4.1 and run to completion. This is changed: REPAIR TABLE and OPTIMIZE TABLE can be killed as of MySQL 4.1.0, as can CHECK TABLE as of MySQL 4.1.3. However, killing a REPAIR TABLE or OPTIMIZE TABLE operation on a MyISAM table results in a table that is corrupted and is unusable (reads and writes to it fail) until you optimize or repair it again (without interruption).'
http://dev.mysql.com/doc/refman/4.1/en/kill.html

And:

'For each thread that is associated with a client connection, the connection to the client is broken and the thread is marked as killed.'
http://dev.mysql.com/doc/refman/5.0/en/server-shutdown.html

So, it looks like when an OPTIMIZE is started by a user and then the server is shutdown, it may damage the table in question.
[17 Jun 2009 5:40] Sveta Smirnova
Thank you for the report.

Do you know circumstances needs to repeat this failure? Do they have 2 tables table and TaBle? Please provide output of `dir datadir\database`
[17 Jun 2009 6:16] Roel Van de Paar
> Do you know circumstances needs to repeat this failure? 

Yes, as per the bug report: shutdown server at the right time during an OPTIMIZE. Also see other bugs linked.

> Do they have 2 tables table and TaBle?

This is not possible since it's Windows (Windows is not case-sensitive):

----------
C:\mysql5.1.31\data\roelt>copy con test.MYD
test
^Z
        1 file(s) copied.

C:\mysql5.1.31\data\roelt>copy con Test.MYD
test
Overwrite Test.MYD? (Yes/No/All): 
----------
[17 Jun 2009 7:46] Shane Bester
I discussed this with ingo once. there's simply no worthwhile way to fix it, and it was agreed to not fix it.  same with repair table.  see bug #25433 for those comments..
[17 Jun 2009 7:51] Sveta Smirnova
Thank you for the report.

Verified as described.

To repeat:

1. Modify source as following:

=== modified file 'storage/myisam/mi_check.c'
--- storage/myisam/mi_check.c   2009-02-13 16:41:47 +0000
+++ storage/myisam/mi_check.c   2009-06-17 07:24:36 +0000
@@ -1979,6 +1979,8 @@
   /* Flush key cache for this file if we are calling this outside myisamchk */
   flush_key_blocks(share->key_cache,share->kfile, FLUSH_IGNORE_CHANGED);
 
+  sleep(20);
+
   share->state.version=(ulong) time((time_t*) 0);
   old_state= share->state;                     /* save state if not stored */
   r_locks=   share->r_locks;

2. Run attached test case with --manual-gdb option.

3. In gdb:

Version: '5.1.37-debug-log'  socket: '/Users/apple/bzr/mysql-5.1/mysql-test/var/tmp/mysqld.1.sock'  port: 13000  Source distribution
[Switching to process 2991 thread 0x2103]

Breakpoint 1, mysql_parse (thd=<incomplete type>, inBuf=0x606a828 "create table t1(f1 int, f2 varchar(255), KEY (f2))", length=50, found_semicolon=0xb0061dc4) at sql_parse.cc:5865
5865      DBUG_ENTER("mysql_parse");
(gdb) b mi_sort_index
Breakpoint 2 at 0x3e7715: file mi_check.c, line 1934.
(gdb) c
Continuing.

Breakpoint 2, mi_sort_index (param=0xb005bfcc, info=0x6074418, name=0xb005bd00 "./test/t1") at mi_check.c:1934
1934      MYISAM_SHARE *share=info->s;
(gdb) b flush_key_blocks
Breakpoint 3 at 0x4b673d: file mf_keycache.c, line 4005.
Current language:  auto; currently c
(gdb) c
Continuing.

Breakpoint 3, flush_key_blocks (keycache=0x6006c18, file=30, type=FLUSH_IGNORE_CHANGED) at mf_keycache.c:4005
4005      int res= 0;
(gdb) c

4. In another shell session:

mysqladmin shutdown -S /path/to/mysql-5.1/mysql-test/var/tmp/mysqld.1.sock

5. In gdb:

Continuing.
090617 11:46:19 [Note] /Users/apple/bzr/mysql-5.1/sql/mysqld: Normal shutdown

090617 11:46:19 [Note] Event Scheduler: Purging the queue. 0 events
090617 11:46:19 [Note] Got signal 15 to shutdown mysqld

Breakpoint 3, flush_key_blocks (keycache=0x6006c18, file=30, type=FLUSH_KEEP) at mf_keycache.c:4005
4005      int res= 0;
(gdb) c
Continuing.
090617 11:46:22 [Warning] /Users/apple/bzr/mysql-5.1/sql/mysqld: Forcing close of thread 1  user: 'root'

Breakpoint 3, flush_key_blocks (keycache=0x6006c18, file=30, type=FLUSH_RELEASE) at mf_keycache.c:4005
4005      int res= 0;
(gdb) clear
Deleted breakpoint 3 
(gdb) c
Continuing.
090617 11:46:27 [Warning] Forcing shutdown of 3 plugins
090617 11:46:27 [Note] /Users/apple/bzr/mysql-5.1/sql/mysqld: Shutdown complete

Program exited normally.
(gdb) q

6. In another shell session:

$myisamchk var/log/main.bug45541/mysqld.1/data/test/t1.MYI
Checking MyISAM file: var/log/main.bug45541/mysqld.1/data/test/t1.MYI
Data records:    8192   Deleted blocks:       0
myisamchk: warning: Table is marked as crashed and last repair failed
- check file-size
- check record delete-chain
- check key delete-chain
- check index reference
- check data record references index: 1
- check record links
MyISAM-table 'var/log/main.bug45541/mysqld.1/data/test/t1.MYI' is usable but should be fixed
[17 Jun 2009 8:07] Sveta Smirnova
This can be duplicate of bug #25433, but I'd say this feature request is "Gratefully finish OPTIMIZE/REPAIR when shutdown server"
[17 Jun 2009 18:23] James Day
The optimize can't be gracefully completed because the index will be incomplete and the table has to be marked as crashed to force a repair so it will be rebuilt after the restart. The feature request to use a copy instead of modifying the original index is a good one.
[16 Nov 2010 9:14] Roel Van de Paar
Any updates?
[14 Jun 2013 5:09] Shane Bester
It is expected that killing optimize on myisam will leave the table in marked as crashed state.  To prevent that, a copy of the index can be made first.  But then folks will complain about excessive disk space being used, and it taking longer.
In short, I don't see any way to please all.   If we make the optimize thread unkillable, people will complain too, then kill -9 their server, and then complain again that all open tables are marked as corrupt.

So I think this is a *feature request*.  Can you tell me what the requested feature is exactly?  How do you want to handle this situation?

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.048 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.