Bug #17001 Table and server crash on ALTER TABLE
Submitted: 1 Feb 2006 11:38 Modified: 5 Jun 2006 21:41
Reporter: Beat Vontobel (Silver Quality Contributor) (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:5.0.19-BK, 5.0.18 OS:Linux (Linux 2.4.21 (SuSE Professional))
Assigned to: Sergey Vojtovich CPU Architecture:Any

[1 Feb 2006 11:38] Beat Vontobel
Description:
An ALTER TABLE ... COMMENT='...' on a MyISAM table completely crashed that table on our production server today. By "completely crashed" I mean not one of the usual table crashes that can be repaired with REPAIR TABLE or myisamchk, these tools don't even show any errors and the index still seems to be okay - but all the data columns just contained scrambled garbage after adding the comment! The table was completely unusable.

The table itself is very old and its definition unchanged maybe since 4.0 or even one of the last 3.23 builds (but we never skipped a single production release since then).

How to repeat:
I could reproduce the table crash on a clean default install of MySQL 5.0.18, without any settings in my.cnf. In addition to the problem on our production server, that only lost its data but not crashed itself, the test server even crashed the mysqld. I attached the table files from last evenings backup (I used them to reproduce the following steps, just untarred them into the test database of the default installation). The following steps show, that everything with the table seems to be okay, then the ALTER TABLE crashes the server and the same SELECT as before returns only garbage. But a CHECK TABLE or myisamchk show no signs of an error.

mysql5:/usr/local/mysql/data/test # mysql
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 5.0.18-standard

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

mysql> use test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> CHECK TABLE sweditor;
+---------------+-------+----------+----------------------------------------------------------+
| Table         | Op    | Msg_type | Msg_text                                                 |
+---------------+-------+----------+----------------------------------------------------------+
| test.sweditor | check | warning  | 4 clients are using or haven't closed the table properly |
| test.sweditor | check | status   | OK                                                       |
+---------------+-------+----------+----------------------------------------------------------+
2 rows in set (0.00 sec)

mysql> ANALYZE TABLE sweditor;
+---------------+---------+----------+-----------------------------+
| Table         | Op      | Msg_type | Msg_text                    |
+---------------+---------+----------+-----------------------------+
| test.sweditor | analyze | status   | Table is already up to date |
+---------------+---------+----------+-----------------------------+
1 row in set (0.00 sec)

mysql> OPTIMIZE TABLE sweditor;
+---------------+----------+----------+----------+
| Table         | Op       | Msg_type | Msg_text |
+---------------+----------+----------+----------+
| test.sweditor | optimize | status   | OK       |
+---------------+----------+----------+----------+
1 row in set (0.02 sec)

mysql> SELECT * FROM sweditor WHERE id = 1\G
*************************** 1. row ***************************
        id: 1
    region: ch
     titel: Prognose
     autor: Sabine Marbet
       typ: prog
   sprache: de
      text: Im Norden ver?nderlich mit einzelnen Schauern und zeitweise Sonne bei 20 bis 24 Grad. Im S?den sch?n bei 28 Grad. 
inserttime: 20040701145010
1 row in set (0.01 sec)

mysql> ALTER TABLE sweditor COMMENT='destroy';
Query OK, 0 rows affected (0.01 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> SELECT * FROM sweditor WHERE id = 1\G
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> SELECT * FROM sweditor WHERE id = 1\G
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    1
Current database: test

*************************** 1. row ***************************
        id: 1
    region: h      Prognose                                                                        Sabine Marbe
     titel: ognose                                                                        Sabine Marbet                       
     autor: ine Marbet                           prog                                    der
       typ:                                     der
   sprache: dV
      text: 
inserttime: 701145010
1 row in set (0.03 sec)

mysql> CHECK TABLE sweditor;
+---------------+-------+----------+----------+
| Table         | Op    | Msg_type | Msg_text |
+---------------+-------+----------+----------+
| test.sweditor | check | status   | OK       |
+---------------+-------+----------+----------+
1 row in set (0.01 sec)

mysql> quit
Bye
mysql5:/usr/local/mysql/data/test # /etc/init.d/mysql.server stop
Shutting down MySQL.                                                                                         done
mysql5:/usr/local/mysql/data/test # myisamchk --extend-check sweditor 
Checking MyISAM file: sweditor
Data records:     173   Deleted blocks:       0
- check file-size
- check record delete-chain
- check key delete-chain
- check index reference
- check data record references index: 1
- check records and index references
[1 Feb 2006 11:59] Valeriy Kravchuk
Thank you for a problem report. So, you had never dumped and restored that table in 5.0.18, just copied it "as is" from version <=4.0, right?
[1 Feb 2006 12:12] Beat Vontobel
Yes, the table is still original (but probably 4.0, not 3.23 - I'm just not 100% sure about this). But actually the upgrade notes never said you have to dump all your databases and re-import them.
[1 Feb 2006 13:25] Beat Vontobel
Just as additional info: The table content was always destroyed by doing the above ALTER TABLE. But mysqld reacted differently regarding crashes.

1) On the production server, with the original table in place, I experienced no server crash at all. Just the table contents were destroyed.
2) I installed the same table (attachment) with a different name on the production server to do more tests. The server crashed immediately on the ALTER TABLE statement. Same corruption as in 1.
3) I did the test (as above in "How to reproduce") on a clean default install with the same table files. The server didn't crash on the ALTER TABLE but on the first SELECT after that. Same corruption as in 1 and 2.

This is the stack dump from test 3)

Version: '5.0.18-standard'  socket: '/tmp/mysql.sock'  port: 3306  MySQL Community Edition - Standard (GPL)
mysqld got signal 11;
This could be because you hit a bug. [...]

key_buffer_size=8388600
read_buffer_size=131072
max_used_connections=1
max_connections=100
threads_connected=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 225791 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x8a0f4d0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
Cannot determine thread, fp=0x425b5808, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x81536e8 handle_segfault + 356
0x4003c96c _end + 934271388
0x4016b1b5 _end + 935510501
0x814f4ab _ZN15Protocol_simple5storeEP5Field + 411
0x80ee77d _ZN10Item_field4sendEP8ProtocolP6String + 21
0x81488ad _ZN11select_send9send_dataER4ListI4ItemE + 201
0x819eeb9 _Z8end_sendP4JOINP13st_join_tableb + 485
0x819e630 _Z9do_selectP4JOINP4ListI4ItemEP8st_tableP9Procedure + 632
0x8194795 _ZN4JOIN4execEv + 4121
0x81952d5 _Z12mysql_selectP3THDPPP4ItemP13st_table_listjR4ListIS1_ES2_jP8st_orderSB_S2_SB_mP13select_resultP18st_select_
lex_unitP13st_sel + 305
0x819135e _Z13handle_selectP3THDP6st_lexP13select_resultm + 234
0x8167301 _Z21mysql_execute_commandP3THD + 585
0x816e176 _Z11mysql_parseP3THDPcj + 306
0x8165c3e _Z16dispatch_command19enum_server_commandP3THDPcj + 1178
0x8165769 _Z10do_commandP3THD + 129
0x8164c71 handle_one_connection + 609
0x40036f60 _end + 934248336
0x401cc327 _end + 935908183
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/mysql/en/Using_stack_trace.html and follow instructions on how to resolve the stack
 trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do 
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x8a2ea30 = SELECT * FROM sweditor WHERE id = 1
thd->thread_id=1
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.

Number of processes running now: 0

And this is the stack dump from test 2)

060104 18:23:35 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.0.18-standard-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Edition - Standard (GPL
)
mysqld got signal 11;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=536870912
read_buffer_size=2093056
max_used_connections=131
max_connections=300
threads_connected=15
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 1751885 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x77d3d250
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
Cannot determine thread, fp=0x6642f788, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x81536e8 handle_segfault + 356
0x4003b96c _end + 934267292
0x4016a1b5 _end + 935506405
0x814f4ab _ZN15Protocol_simple5storeEP5Field + 411
0x80ee77d _ZN10Item_field4sendEP8ProtocolP6String + 21
0x81488ad _ZN11select_send9send_dataER4ListI4ItemE + 201
Stack trace seems successful - bottom reached
Please read http://dev.mysql.com/doc/mysql/en/Using_stack_trace.html and follow instructions on how to resolve the stack
 trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do 
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x661c7078  is invalid pointer
thd->thread_id=2237286
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.

Number of processes running now: 0
060201 10:55:44  mysqld restarted
060201 10:55:45  InnoDB: Database was not shut down normally!
[4 Feb 2006 16:03] James Day
Beat, MySQL Support asked for the following note to be added to the 5.0 download page:

"MySQL generally recommends that you dump and reload your tables from any previous version to upgrade to 5.0."

It probably wasn't there when you first switched. It's not pro-forma dump and reload, it's "you really might see corruption if you don't". We've seen a few odd issues with data corruption on upgrade which we haven't yet pinned down. If your case is repeatable and turns out to be one of these anomalies, that would be great, because we could find a cause. If not, self-defence is dump and reload on upgrade, pain though it is. Please do everything you can to help Valeriy pin this down - we really want this fixed!
[7 Feb 2006 14:58] Beat Vontobel
> Please do everything you can to help Valeriy pin
> this down - we really want this fixed!

James, Valeriy, I'll do my best to help you with this (as time allows). Just ask if you need any more information from me.

As I need pretty much planning on how to dump and reload a critical 24/7 production server anyway, the old tables will stay in place for some time for testing (some of them are less critical, so I should be able to do a little bit of testing there). I just told all admins to not do any ALTER commands on legacy tables meanwhile.
[9 Feb 2006 16:11] Valeriy Kravchuk
Verified just as described on your table (uploaded as private file) on latest 5.0.19-BK (ChangeSet@1.2045, 2006-02-08 17:17:27+01:00):

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 7 to server version: 5.0.19

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

mysql> show tables like 'sw%';
+----------------------+
| Tables_in_test (sw%) |
+----------------------+
| sweditor             |
+----------------------+
1 row in set (0.00 sec)

mysql> show create table sweditor;
...
| sweditor | CREATE TABLE `sweditor` (
  `id` bigint(20) NOT NULL auto_increment,
  `region` varchar(8) NOT NULL default '',
  `titel` varchar(80) NOT NULL default '',
  `autor` varchar(40) NOT NULL default '',
  `typ` varchar(40) NOT NULL default '',
  `sprache` char(2) NOT NULL default '',
  `text` text NOT NULL,
  `inserttime` varchar(14) NOT NULL default '',
  PRIMARY KEY  (`id`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1 |
...
1 row in set (0.00 sec)

mysql> check table sweditor;
+---------------+-------+----------+----------------------------------------------------------+
| Table         | Op    | Msg_type | Msg_text              |
+---------------+-------+----------+----------------------------------------------------------+
| test.sweditor | check | warning  | 4 clients are using or haven't closed the table properly |
| test.sweditor | check | status   | OK              |
+---------------+-------+----------+----------------------------------------------------------+
2 rows in set (0.01 sec)

mysql> analyze table sweditor;
+---------------+---------+----------+-----------------------------+
| Table         | Op      | Msg_type | Msg_text                    |
+---------------+---------+----------+-----------------------------+
| test.sweditor | analyze | status   | Table is already up to date |
+---------------+---------+----------+-----------------------------+
1 row in set (0.00 sec)

mysql> optimize table sweditor;
+---------------+----------+----------+----------+
| Table         | Op       | Msg_type | Msg_text |
+---------------+----------+----------+----------+
| test.sweditor | optimize | status   | OK       |
+---------------+----------+----------+----------+
1 row in set (0.01 sec)

mysql> select * from sweditor where id=1\G
*************************** 1. row ***************************
        id: 1
    region: ch
     titel: Prognose
     autor: Sabine Marbet
       typ: prog
   sprache: de
      text: Im Norden verдnderlich mit einzelnen Schauern und zeitweise Sonne be
i 20 bis 24 Grad. Im Sьden schцn bei 28 Grad.
inserttime: 20040701145010
1 row in set (0.00 sec)

mysql> ALTER TABLE sweditor COMMENT='destroy';
Query OK, 0 rows affected (0.01 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> select * from sweditor where id=1\G
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql>
Number of processes running now: 0
060204 20:17:40  mysqld restarted
mysql> select * from sweditor where id=1\G
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    3
Current database: test

*************************** 1. row ***************************
        id: 1
    region: h      Prognose
                   Sabine Marbe
     titel: ognose
          Sabine Marbet
     autor: ine Marbet                           prog
         der
       typ:                                     der
   sprache: Дь
      text:
inserttime: 701145010
1 row in set (0.08 sec)

mysql> check table sweditor;
+---------------+-------+----------+----------+
| Table         | Op    | Msg_type | Msg_text |
+---------------+-------+----------+----------+
| test.sweditor | check | status   | OK       |
+---------------+-------+----------+----------+
1 row in set (0.01 sec)

mysql> quit
Bye
openxs@suse:~/dbs/5.0> bin/mysqladmin -uroot shutdown
STOPPING server from pid file /home/openxs/dbs/5.0/var/suse.pid
060204 20:18:10  mysqld ended

[1]+  Done                    bin/mysqld_safe
openxs@suse:~/dbs/5.0> cd var/test; ../../bin/myisamchk --extend-check sweditor

Checking MyISAM file: sweditor
Data records:     173   Deleted blocks:       0
- check file-size
- check record delete-chain
- check key delete-chain
- check index reference
- check data record references index: 1
- check records and index references

And there was a crash. I can send the resolved stack trace, if somebody needs it, but the crash is 100% repeatable with table uploaded.
[9 Feb 2006 16:14] Valeriy Kravchuk
My resolved stack trace looked different, so here it is:

openxs@suse:~/dbs/5.0> bin/resolve_stack_dump -s /tmp/mysqld.sym -n 17001.stack

0x817c166 handle_segfault + 566
0xffffe420 _end + -140322872
0x8ac2e00 _end + 5185960
0x816b399 _ZN11select_send9send_dataER4ListI4ItemE + 185
0x81c9b1b _Z8end_sendP4JOINP13st_join_tableb + 283
0x81d75fc _Z9do_selectP4JOINP4ListI4ItemEP8st_tableP9Procedure + 684
0x81e6d42 _ZN4JOIN4execEv + 4258
0x81e3b70 _Z12mysql_selectP3THDPPP4ItemP13st_table_listjR4ListIS1_ES2_jP8st_orde
rSB_S2_SB_mP13select_resultP18st_select_lex_unitP13st_sel + 176
0x81e8227 _Z13handle_selectP3THDP6st_lexP13select_resultm + 215
0x8195f62 _Z21mysql_execute_commandP3THD + 14242
0x819bfda _Z11mysql_parseP3THDPcj + 522
0x819e4a0 _Z16dispatch_command19enum_server_commandP3THDPcj + 3344
0x819f6b3 handle_one_connection + 1747
0x4004eaa7 _end + 933748303
0x40249c2e _end + 935825366
[17 Feb 2006 9:12] Valeriy Kravchuk
Bug #17438 was marked as a duplicate of this one.
[21 Apr 2006 11:24] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/5290
[16 May 2006 13:37] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/6463
[24 May 2006 14:05] Sergey Vojtovich
Pushed into tree currently marked as 5.0.23.
[2 Jun 2006 10:42] Sergey Vojtovich
Merged into tree currently tagged as 5.1.12.
[5 Jun 2006 21:41] Mike Hillyer
Documented in changelogs:

      <listitem>
        <para>
          ALTER TABLE on a table created prior to 5.0.3 would cause
          table corruption if the ALTER TABLE did one of the following:
        </para>
        
        <itemizedlist>
          <listitem>
            <para>
              Change the default value of a column.
            </para>
          </listitem>
          
          <listitem>
            <para>
              Change the table comment.
            </para>
          </listitem>
          
          <listitem>
            <para>
              Change the table password.
            </para>
          </listitem>
          
        </itemizedlist>
        
        <para>(Bug #6463)</para>
        
      </listitem>
[5 Jun 2006 23:09] James Day
Sergey,

Which storage engines are affected? All?

James Day
Support Engineer, MySQL AB
[6 Jun 2006 7:43] Sergey Vojtovich
James, only MyISAM is affected.
[6 Jun 2006 17:13] James Day
Mike,

Please change the release note to indicate that only MyISAM is affected.

Sergey, thanks.

James Day
Support Engineer, MySQL AB