MySQL Bugs: #50041: mysqlcheck --optimize --auto-repair executes OPTIMIZE first for broken table bin

Bug #50041	mysqlcheck --optimize --auto-repair executes OPTIMIZE first for broken table bin
Submitted:	4 Jan 2010 7:47	Modified:	23 May 2010 23:41
Reporter:	Roel Van de Paar	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	5.1.36,5.5.0m2	OS:	Any
Assigned to:	Assigned Account	CPU Architecture:	Any
Tags:	mysqlcheck

Description:
When executing mysqlcheck --check --optimize --auto-repair it logs - in the binary log - a statement to execute OPTIMIZE first, and only then REPAIR when a table is broken. This means that an OPTIMIZE is attempted first on a slave whereas it should attempt REPAIR first.

-----------
roel@roel-ubuntu-vm:/rep/5136/master/data$ ../bin/mysqlbinlog -v --base64-output=DECODE-ROWS mysql-bin.000004
[...]
# at 2383
#100102 16:47:38 server id 51361 end_log_pos 2469 Query thread_id=6 exec_time=0 error_code=0
use roelt/*!*/;
SET TIMESTAMP=1262411258/*!*/;
OPTIMIZE TABLE `test1`
/*!*/;
# at 2469
#100102 16:47:38 server id 51361 end_log_pos 2561 Query thread_id=6 exec_time=0 error_code=0
SET TIMESTAMP=1262411258/*!*/;
REPAIR TABLE `break`.`test1`
/*!*/;
-----------

How to repeat:
On the master:

#1 Create a table, and while doing so, kill -9 <mysqld pid>. To create a large table, use:

DROP TABLE IF EXISTS test1;
CREATE TABLE test1 (id int) ENGINE=MyISAM;
INSERT INTO test1 VALUES (1),(2),(3),(4),(5);
INSERT INTO test1 select a.id FROM test1 AS a, test1 AS b, test1 as c, test1 as d, test1 as e, test1 as f, test1 as g, test1 as h, test1 as i, test1 as j;

Interrupt after about 5 seconds (kill -9) and use CHECK TABLE test1; to verify table is broke ('Table is marked as crashed').

#2 For clarity, execute FLUSH LOGS; (start new binlog file)

#3 Execute: ./mysqlcheck -uroot --check --optimize --all-databases --auto-repair

Observe error:

-------
roelt.test1
Error    : Table './roelt/test1' is marked as crashed and should be repaired
Error    : Table 'test1' is marked as crashed and should be repaired
error    : Corrupt

Repairing tables
roelt.test1
warning  : Number of rows changed from 5 to 3819812
status   : OK
-------

#4 Observe binlog (this statement is assuming ROW based replication):

./mysqlbinlog -v --base64-output=DECODE-ROWS <binlog in use after FLUSH LOGS>

Same issue happens if options are reversed (.

Suggested fix:
Run REPAIR first, then OPTIMIZE.

Verifying as D3

Suggested workaround: run the command twice, once with --repair and a second time with --optimize.

The manual says "--auto-repair   If a checked table is corrupted, automatically fix it."
How can mysqlcheck know that a table has crashed? Only after doing check, optimize or others actions. So optimizing, in principle, is executed before repair. After a corruption, even though the table is repaired, but the optimizing on it is not completed, even nothing is optimized. We have to call
mysqlcheck second time to optimize the repaired table.

So I don't think this is a bug of replication.

> After a corruption, even though the table is repaired, but the optimizing on it is not completed, even nothing is optimized. We have to call mysqlcheck second time to optimize the repaired table.

If this is the case, it looks like this is an *additional* bug in mysqlcheck. If --check, --optimize, and --auto-repair are specified, it should check the table, repair the table if corrupted and then optimize it (logical order), unless this is expected behavior, in which case the manual should state so.

And, though this is interesting, I do not think it is relevant to this bug:

The observed and reported behavior is that when running mysqlcheck --check --optimize --auto-repair it logs - in the binary log - a statement to execute OPTIMIZE first, and only then REPAIR when a table is broken.

This is illogical and needs to be reversed. If mysqlcheck --check --optimize --auto-repair was executed, the binary logs need to record first the REPAIR, then OPTIMIZE.

Hi Roel Van de Paar,
Please look at the bug Bug#35269.
When executing 'mysqlcheck --check --optimize --auto-repair', Only 'OPTIMIZE ...' is executed, 'CHECK ..' is not executed absolutely. 

So It is better to add comments about this bug into bug#35269. 
When fixing bug#35269, they will notice the comments and consider whether the
principle should be changed or not.

> When executing 'mysqlcheck --check --optimize --auto-repair', Only 'OPTIMIZE ...' is executed, 'CHECK ..' is not executed absolutely. 

It's messy:

#1 Copy in a broken table

C:\mysql5146\data\roelt\broke>copy * ..
test1.frm
test1.MYD
test1.MYI
        3 file(s) copied.

#2 Execute mysqlcheck

C:\mysql5146\bin>mysqlcheck -uroot --check --optimize --all-databases --auto-repair -P5146
[...]
roelt.test1                                        OK    <-------- The table is not recognized as broken
[...]

C:\mysql5146\bin>mysql -uroot -P5146 roelt
[...]
mysql> check table test1;
+-------------+-------+----------+-------------------------------------------------+
| Table       | Op    | Msg_type | Msg_text                                        |
+-------------+-------+----------+-------------------------------------------------+
| roelt.test1 | check | warning  | Size of datafile is: 36       Should be: 35     |
| roelt.test1 | check | error    | got error: 0 when reading datafile at record: 5 |
| roelt.test1 | check | error    | Corrupt                                         |
+-------------+-------+----------+-------------------------------------------------+
3 rows in set (0.02 sec)

mysql> check table test1;
+-------------+-------+----------+-------------------------------------------------+
| Table       | Op    | Msg_type | Msg_text                                        |
+-------------+-------+----------+-------------------------------------------------+
| roelt.test1 | check | warning  | Table is marked as crashed                      |
| roelt.test1 | check | warning  | Size of datafile is: 36       Should be: 35     |
| roelt.test1 | check | error    | got error: 0 when reading datafile at record: 5 |
| roelt.test1 | check | error    | Corrupt                                         |
+-------------+-------+----------+-------------------------------------------------+
4 rows in set (0.00 sec)

mysql> exit
Bye

C:\mysql5146\bin>mysqlcheck -uroot --check --optimize --all-databases --auto-repair -P5146
[...]
roelt.test1
Error    : Table '.\roelt\test1' is marked as crashed and should be repaired
Error    : Table 'test1' is marked as crashed and should be repaired
error    : Corrupt
[...]
Repairing tables
roelt.test1                                        OK

Exactly the same for:
mysqlcheck -uroot --check --analyze --all-databases --auto-repair -P5146

Bug #35269 is about: mysqlcheck behaving different depending on the order of parameters

This bug is about OPTIMIZE being attempted first and notes: "Same issue happens if options are reversed"

Though they look related, for the moment I would like to keep both bugs open.

Besides that, this bug is also about an illogical order in the binlog thereby possibly affecting how the slave operates.

Marking as a duplicate of bug 

In correction of the notes above, when the order is reversed (mysqlcheck --optimize --check --auto-repair) only REPAIR appears in the binary log.

Also, the original test case uses CHECK TABLE to establish that the table is broken, thereby affecting the operation of mysqlcheck.

Marked as duplicate of bug #35269